Summary:	ASTERISK-29064: res_rtp_asterisk: Audio Delay on WebRTC Call from Delayed ICE Completion
Reporter:	Oliver Rafael Peña (oliver.pena)	Labels:	webrtc
Date Opened:	2020-09-02 18:34:38	Date Closed:
Priority:	Major	Regression?
Status:	Open/New	Components:	Channels/chan_pjsip Resources/res_rtp_asterisk
Versions:	16.9.0	Frequency of Occurrence	Frequent
Related Issues:
Environment:	OS: CentOS Linux release 7.7.1908 (Core) CPU Cores: 2 RAM: 4GB Client WebRTC Librery: sip.js 0.15.0 Chrome version: 85.0.4183.83 Asterisk Behind NAT: yes Client behind NAT: yes	Attachments:	( 0) audio_delay_call_-_15_seconds_no_audio.pcapng ( 1) audio_delay_call_-_15_seconds_no_audio_SIP_Messages.txt ( 2) Audio_Delay_Call_-_udp_capture.pcapng ( 3) Audio_Delay_Example_3_-_Captutre_Client_Side.pcapng ( 4) Audio_Delay_Example_3_-_SIP_Messages.txt ( 5) Audio_Delay_SIP_Messages.txt ( 6) debug_15seconds_noaudio_call.txt ( 7) debug_asterisk_Example_3.txt
Description:	Greetings, We've deployed asterisk + webrtc in a production enviroment, and since day one we've been having a problem with calls having audio delay  on both ways, this happens on ~10% of the calls, users are more often to identify the problem on outbound calls. The delay goes around 1-10 seconds, it vary. We understand that WebRTC comes with its requirements, and after a few months of research and testing we've done the following trying to solve the problem: - Even though we didn't find any fragmentation of DTLS packets on the handshake we decided to activate the pjsip endpoints option "dtls_auto_generate_cert" to discard any problems there. - Also we proceed to remove all unnecessary ICE candidates out of the client's end to ease ICE negotiation, along with reducing the ICE timeout to 500ms on the client - Also we remove the stunaddr option out of rtp.conf since we know the public IP, therefore removing the stun request out of the process. And after all that we still have the issue, hopefully we can clear that out on this thread. Based on our most recent testing, we noticed that asterisk is taking a considerable amount of time to initiate the DTLS handshake, roughly 2 seconds after the ICE bindings are done, in the capture file attached you can see that. The users perceived around 4-5 seconds of none audio at the beginning of this call. Here are the config files: pjsip.endpoint.conf {panel} [base_webrtc](!) type=endpoint auth=main_auth transport=0.0.0.0-wss allow=ulaw,alaw,gsm,g726,g722 context=from-internal dtmf_mode=rfc4733 mwi_subscribe_replaces_unsolicited=yes aggregate_mwi=yes use_avpf=yes rtcp_mux=yes ice_support=yes media_use_received_transport=no trust_id_inbound=yes direct_media=no timers=no media_encryption_optimistic=yes send_pai=yes rtp_symmetric=yes rewrite_contact=yes force_rport=yes language=en media_encryption=dtls dtls_verify=fingerprint dtls_auto_generate_cert=yes dtls_setup=actpass dtls_rekey=0 webrtc=yes rtp_keepalive=2 [1922285](base_webrtc) aors=1922285 callerid=CallerID <1922285> mailboxes=1922285@device {panel} rtp.conf {panel} [general] rtpstart=50000 rtpend=55000 rtpchecksums=yes strictrtp=no icesupport=yes [ice_host_candidates] x.x.x.x => y.y.y.y,include_local_address ; x.x.x.x is the internal IP, y.y.y.y is the external IP {panel} http.conf {panel} [general] enabled=yes enablestatic=no bindaddr=:: bindport=8088 prefix= sessionlimit=1000 session_inactivity=30000 session_keep_alive=15000 tlsenable=yes tlsbindaddr=[::]:8089 tlscertfile=/etc/asterisk/keys/cert.crt tlsprivatekey=/etc/asterisk/keys/keyl.key {panel}
Comments:	By: Asterisk Team (asteriskteam) 2020-09-02 18:34:40.539-0500 Thanks for creating a report! The issue has entered the triage process. That means the issue will wait in this status until a Bug Marshal has an opportunity to review the issue. Once the issue has been reviewed you will receive comments regarding the next steps towards resolution. Please note that log messages and other files should not be sent to the Sangoma Asterisk Team unless explicitly asked for. All files should be placed on this issue in a sanitized fashion as needed. A good first step is for you to review the [Asterisk Issue Guidelines|https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines] if you haven't already. The guidelines detail what is expected from an Asterisk issue report. Then, if you are submitting a patch, please review the [Patch Contribution Process|https://wiki.asterisk.org/wiki/display/AST/Patch+Contribution+Process]. Please note that once your issue enters an open state it has been accepted. As Asterisk is an open source project there is no guarantee or timeframe on when your issue will be looked into. If you need expedient resolution you will need to find and pay a suitable developer. Asking for an update on your issue will not yield any progress on it and will not result in a response. All updates are posted to the issue when they occur. By: Oliver Rafael Peña (oliver.pena) 2020-09-02 18:36:13.363-0500 The capture and sip messages were extracted on the WebRTC client's end By: Joshua C. Colp (jcolp) 2020-09-03 03:41:13.158-0500 We require additional debug to continue with triage of your issue. Please follow the instructions on the wiki [1] for how to collect debugging information from Asterisk. For expediency, where possible, attach the debug with a '.txt' file extension so that the debug will be usable for further analysis. Thanks! [1] https://wiki.asterisk.org/wiki/display/AST/Collecting+Debug+Information By: Kevin Harwell (kharwell) 2020-09-03 09:25:54.393-0500 Is a VPN involved? By: Oliver Rafael Peña (oliver.pena) 2020-09-03 09:29:29.718-0500 For this particular test yes, there is a full tunnel VPN on the client's end, but this is not the case for production users. By: Oliver Rafael Peña (oliver.pena) 2020-09-03 10:19:31.241-0500 Find attached another example of the problem, this time the WebRTC client is not on a VPN, and includes Asterisk Debug file. Note: The user got into the VM of the dialed number, and could not hear the audio, after ~15 seconds. By: Benjamin Keith Ford (bford) 2020-09-09 13:37:11.366-0500 Can you get the same logs but with much higher debug levels (i.e., 9)? Also, can you provide some clarification on the IP addresses so we can follow the conversation between them? By: Oliver Rafael Peña (oliver.pena) 2020-09-09 14:50:36.731-0500 Here's another example with debug on 9999. This time the DTLS handshake was done after 6 seconds of the SDP exchange was completed. In the SIP Messages file there is a note on the IP addresses public/private on each end. By: Benjamin Keith Ford (bford) 2020-09-10 11:26:19.919-0500 From the logs, ICE completion is taking quite a while to actually complete. I'm going to open an issue for this to investigate further. By: Oliver Rafael Peña (oliver.pena) 2020-09-24 08:31:47.907-0500 Greetings Team, Please let me know if you need any other information to tackle this issue. Regards, By: Joshua C. Colp (jcolp) 2020-09-24 08:35:44.351-0500 The issue has been opened, if any additional information is needed or the issue is being worked on then it will be updated. There is no timeframe on when issues are looked into or resolved. By: Oliver Rafael Peña (oliver.pena) 2020-10-07 08:21:21.378-0500 We managed to put a simple workaround in place, by using Early media in the WebRTC client call leg, by adding: Answer() and a Playback(silence/1) just before the Dial sentence, that way the SDP exchange occurs right away along with DTLS handshake.