can you confirm if the behavior is the same using verto? please open a bug at <a href="https://FreeSWITCH.org/jira">https://FreeSWITCH.org/jira</a> on this issue.<span></span><br><br>On Saturday, June 20, 2015, Adam Ben-Ayoun <<a href="mailto:adam.ben.ayoun1@gmail.com">adam.ben.ayoun1@gmail.com</a>> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div dir="ltr">Hi guys,<div><br></div><div>Since we upgraded to 1.6, it takes up to 5 seconds for media to actually flow after DTLS state becomes READY, this did not happen on 1.4. We are using sipjs and test clients on Android and iOS, the issue reproduces on all of them. Connection time used to take about 2.5-3 seconds and now it actually takes 7-8 seconds.</div><div><br></div><div>Here are the relevant FreeSWITCH logs:</div><div><br></div><div><br></div><div><div>2015-06-20 16:28:36.458187 [DEBUG] sofia.c:6701 Channel sofia/internal/anonymous.jb4692@anonymous.invalid entering state [ready][200]</div><div>nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering</div><div>nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering</div><div>nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering</div><div>nta.c:1289 agent_timer() nta: timer not set</div><div>2015-06-20 16:28:37.838233 [INFO] switch_rtp.c:3006 Changing audio DTLS state from HANDSHAKE to SETUP</div><div>2015-06-20 16:28:37.838233 [INFO] switch_rtp.c:2915 audio Fingerprint Verified.</div><div>2015-06-20 16:28:37.838233 [INFO] switch_rtp.c:3495 Activating Audio Secure RTP SEND</div><div>2015-06-20 16:28:37.838233 [DEBUG] switch_core_sqldb.c:2599 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80</div><div>2015-06-20 16:28:37.838233 [INFO] switch_rtp.c:3473 Activating Audio Secure RTP RECV</div><div>2015-06-20 16:28:37.838233 [DEBUG] switch_core_sqldb.c:2599 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80</div><div>2015-06-20 16:28:37.838233 [INFO] switch_rtp.c:2955 Changing audio DTLS state from SETUP to READY</div><div>2015-06-20 16:28:37.838233 [NOTICE] mod_dptools.c:1292 Channel [sofia/internal/anonymous.jb4692@anonymous.invalid] has been answered</div><div>2015-06-20 16:28:37.838233 [DEBUG] switch_channel.c:3759 (sofia/internal/anonymous.jb4692@anonymous.invalid) Callstate Change EARLY -> ACTIVE</div><div>2015-06-20 16:28:37.838233 [DEBUG] switch_ivr.c:195 Codec Activated L16@16000hz 1 channels 30ms</div><div>2015-06-20 16:28:37.878249 [DEBUG] switch_rtp.c:1775 rtcp_stats_init: audio ssrc[3304298062] base_seq[31262]</div><div>EXECUTE sofia/internal/anonymous.jb4692@anonymous.invalid conference(1234-172.30.0.123@test)</div><div>2015-06-20 16:28:41.878188 [INFO] mod_conference.c:13067 using channel sound prefix: /usr/local/freeswitch/sounds/en/us/callie</div><div>2015-06-20 16:28:41.878188 [DEBUG] mod_conference.c:11570 Raw Codec Activation Success L16@16000hz 1 channel 30ms</div><div>2015-06-20 16:28:41.878188 [DEBUG] mod_conference.c:11617 Raw Codec Activation Success L16@16000hz 1 channel 30ms</div><div>2015-06-20 16:28:41.878188 [DEBUG] switch_core_codec.c:221 sofia/internal/anonymous.jb4692@anonymous.invalid Push codec L16:100</div><div>2015-06-20 16:28:41.878188 [DEBUG] mod_conference.c:4992 Setup timer success interval: 30 samples: 480</div><div>2015-06-20 16:28:41.898176 [INFO] mod_conference.c:13676 sofia/internal/anonymous.jb4692@anonymous.invalid binding '0' to 'mute'</div><div>2015-06-20 16:28:41.898176 [INFO] switch_ivr_async.c:213 Digit parser mod_conference: Setting realm to 'conf'</div><div>2015-06-20 16:28:41.898176 [DEBUG] switch_ivr_async.c:322 Digit parser mod_conference: binding 0/conf/0 callback: 0x7f429d09adb0 data: 0x7f4290166f18</div><div>2015-06-20 16:28:41.898176 [INFO] mod_conference.c:13676 sofia/internal/anonymous.jb4692@anonymous.invalid binding '*' to 'deaf mute'</div><div>2015-06-20 16:28:41.898176 [DEBUG] switch_ivr_async.c:322 Digit parser mod_conference: binding */conf/0 callback: 0x7f429d09adb0 data: 0x7f4290166f48</div><div>2015-06-20 16:28:41.898176 [INFO] mod_conference.c:13676 sofia/internal/anonymous.jb4692@anonymous.invalid binding '9' to 'energy up'</div><div>2015-06-20 16:28:41.898176 [DEBUG] switch_ivr_async.c:322 Digit parser mod_conference: binding 9/conf/0 callback: 0x7f429d09adb0 data: 0x7f4290166f78</div><div>2015-06-20 16:28:41.898176 [INFO] mod_conference.c:13676 sofia/internal/anonymous.jb4692@anonymous.invalid binding '8' to 'energy equ'</div><div>2015-06-20 16:28:41.898176 [DEBUG] switch_ivr_async.c:322 Digit parser mod_conference: binding 8/conf/0 callback: 0x7f429d09adb0 data: 0x7f4290166fa8</div><div>2015-06-20 16:28:41.898176 [INFO] mod_conference.c:13676 sofia/internal/anonymous.jb4692@anonymous.invalid binding '7' to 'energy dn'</div><div>2015-06-20 16:28:41.898176 [DEBUG] switch_ivr_async.c:322 Digit parser mod_conference: binding 7/conf/0 callback: 0x7f429d09adb0 data: 0x7f4290166fd8</div><div>2015-06-20 16:28:41.898176 [INFO] mod_conference.c:13676 sofia/internal/anonymous.jb4692@anonymous.invalid binding '3' to 'vol talk up'</div><div>2015-06-20 16:28:41.898176 [DEBUG] switch_ivr_async.c:322 Digit parser mod_conference: binding 3/conf/0 callback: 0x7f429d09adb0 data: 0x7f4290167008</div><div>2015-06-20 16:28:41.898176 [INFO] mod_conference.c:13676 sofia/internal/anonymous.jb4692@anonymous.invalid binding '2' to 'vol talk zero'</div><div>2015-06-20 16:28:41.898176 [DEBUG] switch_ivr_async.c:322 Digit parser mod_conference: binding 2/conf/0 callback: 0x7f429d09adb0 data: 0x7f4290167038</div><div>2015-06-20 16:28:41.898176 [INFO] mod_conference.c:13676 sofia/internal/anonymous.jb4692@anonymous.invalid binding '1' to 'vol talk dn'</div><div>2015-06-20 16:28:41.898176 [DEBUG] switch_ivr_async.c:322 Digit parser mod_conference: binding 1/conf/0 callback: 0x7f429d09adb0 data: 0x7f4290167068</div><div>2015-06-20 16:28:41.898176 [INFO] mod_conference.c:13676 sofia/internal/anonymous.jb4692@anonymous.invalid binding '6' to 'vol listen up'</div><div>2015-06-20 16:28:41.898176 [DEBUG] switch_ivr_async.c:322 Digit parser mod_conference: binding 6/conf/0 callback: 0x7f429d09adb0 data: 0x7f4290167098</div><div>2015-06-20 16:28:41.898176 [INFO] mod_conference.c:13676 sofia/internal/anonymous.jb4692@anonymous.invalid binding '5' to 'vol listen zero'</div><div>2015-06-20 16:28:41.898176 [DEBUG] switch_ivr_async.c:322 Digit parser mod_conference: binding 5/conf/0 callback: 0x7f429d09adb0 data: 0x7f42901670c8</div><div>2015-06-20 16:28:41.898176 [INFO] mod_conference.c:13676 sofia/internal/anonymous.jb4692@anonymous.invalid binding '4' to 'vol listen dn'</div><div>2015-06-20 16:28:41.898176 [DEBUG] switch_ivr_async.c:322 Digit parser mod_conference: binding 4/conf/0 callback: 0x7f429d09adb0 data: 0x7f42901670f8</div><div>2015-06-20 16:28:41.898176 [INFO] mod_conference.c:13676 sofia/internal/anonymous.jb4692@anonymous.invalid binding '#' to 'hangup'</div><div>2015-06-20 16:28:41.898176 [DEBUG] switch_ivr_async.c:322 Digit parser mod_conference: binding #/conf/0 callback: 0x7f429d09adb0 data: 0x7f4290167128</div><div>2015-06-20 16:28:41.898176 [DEBUG] mod_conference.c:6751 Setup timer soft success interval: 30 samples: 480</div><div>2015-06-20 16:28:41.918188 [DEBUG] mod_conference.c:5127 Auto recording file: /tmp/record.wav</div><div>2015-06-20 16:28:41.938180 [DEBUG] mod_conference.c:7178 Setup timer success interval: 30 samples: 480</div></div><div><br></div><div>As you can see at 2015-06-20 16:28:37.838233, the DTLS handshake completed, the call was answered and the client is thinking that media is connect but in fact only at 2015-06-20 16:28:41.938180 media opens. Any idea?</div><div><br></div><div>Thanks,</div><div>Adam</div></div>
</blockquote>