can you confirm if the behavior is the same using verto? please open a bug at https://FreeSWITCH.org/jira on this issue.
On Saturday, June 20, 2015, Adam Ben-Ayoun <adam.ben.ayoun1@gmail.com> wrote:Hi guys,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.Here are the relevant FreeSWITCH logs:2015-06-20 16:28:36.458187 [DEBUG] sofia.c:6701 Channel sofia/internal/anonymous.jb4692@anonymous.invalid entering state [ready][200]nua.c:366 nua_handle_magic() nua: nua_handle_magic: enteringnua.c:366 nua_handle_magic() nua: nua_handle_magic: enteringnua.c:366 nua_handle_magic() nua: nua_handle_magic: enteringnta.c:1289 agent_timer() nta: timer not set2015-06-20 16:28:37.838233 [INFO] switch_rtp.c:3006 Changing audio DTLS state from HANDSHAKE to SETUP2015-06-20 16:28:37.838233 [INFO] switch_rtp.c:2915 audio Fingerprint Verified.2015-06-20 16:28:37.838233 [INFO] switch_rtp.c:3495 Activating Audio Secure RTP SEND2015-06-20 16:28:37.838233 [DEBUG] switch_core_sqldb.c:2599 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_802015-06-20 16:28:37.838233 [INFO] switch_rtp.c:3473 Activating Audio Secure RTP RECV2015-06-20 16:28:37.838233 [DEBUG] switch_core_sqldb.c:2599 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_802015-06-20 16:28:37.838233 [INFO] switch_rtp.c:2955 Changing audio DTLS state from SETUP to READY2015-06-20 16:28:37.838233 [NOTICE] mod_dptools.c:1292 Channel [sofia/internal/anonymous.jb4692@anonymous.invalid] has been answered2015-06-20 16:28:37.838233 [DEBUG] switch_channel.c:3759 (sofia/internal/anonymous.jb4692@anonymous.invalid) Callstate Change EARLY -> ACTIVE2015-06-20 16:28:37.838233 [DEBUG] switch_ivr.c:195 Codec Activated L16@16000hz 1 channels 30ms2015-06-20 16:28:37.878249 [DEBUG] switch_rtp.c:1775 rtcp_stats_init: audio ssrc[3304298062] base_seq[31262]EXECUTE sofia/internal/anonymous.jb4692@anonymous.invalid conference(1234-172.30.0.123@test)2015-06-20 16:28:41.878188 [INFO] mod_conference.c:13067 using channel sound prefix: /usr/local/freeswitch/sounds/en/us/callie2015-06-20 16:28:41.878188 [DEBUG] mod_conference.c:11570 Raw Codec Activation Success L16@16000hz 1 channel 30ms2015-06-20 16:28:41.878188 [DEBUG] mod_conference.c:11617 Raw Codec Activation Success L16@16000hz 1 channel 30ms2015-06-20 16:28:41.878188 [DEBUG] switch_core_codec.c:221 sofia/internal/anonymous.jb4692@anonymous.invalid Push codec L16:1002015-06-20 16:28:41.878188 [DEBUG] mod_conference.c:4992 Setup timer success interval: 30 samples: 4802015-06-20 16:28:41.898176 [INFO] mod_conference.c:13676 sofia/internal/anonymous.jb4692@anonymous.invalid binding '0' to 'mute'2015-06-20 16:28:41.898176 [INFO] switch_ivr_async.c:213 Digit parser mod_conference: Setting realm to 'conf'2015-06-20 16:28:41.898176 [DEBUG] switch_ivr_async.c:322 Digit parser mod_conference: binding 0/conf/0 callback: 0x7f429d09adb0 data: 0x7f4290166f182015-06-20 16:28:41.898176 [INFO] mod_conference.c:13676 sofia/internal/anonymous.jb4692@anonymous.invalid binding '*' to 'deaf mute'2015-06-20 16:28:41.898176 [DEBUG] switch_ivr_async.c:322 Digit parser mod_conference: binding */conf/0 callback: 0x7f429d09adb0 data: 0x7f4290166f482015-06-20 16:28:41.898176 [INFO] mod_conference.c:13676 sofia/internal/anonymous.jb4692@anonymous.invalid binding '9' to 'energy up'2015-06-20 16:28:41.898176 [DEBUG] switch_ivr_async.c:322 Digit parser mod_conference: binding 9/conf/0 callback: 0x7f429d09adb0 data: 0x7f4290166f782015-06-20 16:28:41.898176 [INFO] mod_conference.c:13676 sofia/internal/anonymous.jb4692@anonymous.invalid binding '8' to 'energy equ'2015-06-20 16:28:41.898176 [DEBUG] switch_ivr_async.c:322 Digit parser mod_conference: binding 8/conf/0 callback: 0x7f429d09adb0 data: 0x7f4290166fa82015-06-20 16:28:41.898176 [INFO] mod_conference.c:13676 sofia/internal/anonymous.jb4692@anonymous.invalid binding '7' to 'energy dn'2015-06-20 16:28:41.898176 [DEBUG] switch_ivr_async.c:322 Digit parser mod_conference: binding 7/conf/0 callback: 0x7f429d09adb0 data: 0x7f4290166fd82015-06-20 16:28:41.898176 [INFO] mod_conference.c:13676 sofia/internal/anonymous.jb4692@anonymous.invalid binding '3' to 'vol talk up'2015-06-20 16:28:41.898176 [DEBUG] switch_ivr_async.c:322 Digit parser mod_conference: binding 3/conf/0 callback: 0x7f429d09adb0 data: 0x7f42901670082015-06-20 16:28:41.898176 [INFO] mod_conference.c:13676 sofia/internal/anonymous.jb4692@anonymous.invalid binding '2' to 'vol talk zero'2015-06-20 16:28:41.898176 [DEBUG] switch_ivr_async.c:322 Digit parser mod_conference: binding 2/conf/0 callback: 0x7f429d09adb0 data: 0x7f42901670382015-06-20 16:28:41.898176 [INFO] mod_conference.c:13676 sofia/internal/anonymous.jb4692@anonymous.invalid binding '1' to 'vol talk dn'2015-06-20 16:28:41.898176 [DEBUG] switch_ivr_async.c:322 Digit parser mod_conference: binding 1/conf/0 callback: 0x7f429d09adb0 data: 0x7f42901670682015-06-20 16:28:41.898176 [INFO] mod_conference.c:13676 sofia/internal/anonymous.jb4692@anonymous.invalid binding '6' to 'vol listen up'2015-06-20 16:28:41.898176 [DEBUG] switch_ivr_async.c:322 Digit parser mod_conference: binding 6/conf/0 callback: 0x7f429d09adb0 data: 0x7f42901670982015-06-20 16:28:41.898176 [INFO] mod_conference.c:13676 sofia/internal/anonymous.jb4692@anonymous.invalid binding '5' to 'vol listen zero'2015-06-20 16:28:41.898176 [DEBUG] switch_ivr_async.c:322 Digit parser mod_conference: binding 5/conf/0 callback: 0x7f429d09adb0 data: 0x7f42901670c82015-06-20 16:28:41.898176 [INFO] mod_conference.c:13676 sofia/internal/anonymous.jb4692@anonymous.invalid binding '4' to 'vol listen dn'2015-06-20 16:28:41.898176 [DEBUG] switch_ivr_async.c:322 Digit parser mod_conference: binding 4/conf/0 callback: 0x7f429d09adb0 data: 0x7f42901670f82015-06-20 16:28:41.898176 [INFO] mod_conference.c:13676 sofia/internal/anonymous.jb4692@anonymous.invalid binding '#' to 'hangup'2015-06-20 16:28:41.898176 [DEBUG] switch_ivr_async.c:322 Digit parser mod_conference: binding #/conf/0 callback: 0x7f429d09adb0 data: 0x7f42901671282015-06-20 16:28:41.898176 [DEBUG] mod_conference.c:6751 Setup timer soft success interval: 30 samples: 4802015-06-20 16:28:41.918188 [DEBUG] mod_conference.c:5127 Auto recording file: /tmp/record.wav2015-06-20 16:28:41.938180 [DEBUG] mod_conference.c:7178 Setup timer success interval: 30 samples: 480As 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?Thanks,Adam
_________________________________________________________________________
Professional FreeSWITCH Consulting Services:
consulting@freeswitch.org
http://www.freeswitchsolutions.com
Official FreeSWITCH Sites
http://www.freeswitch.org
http://confluence.freeswitch.org
http://www.cluecon.com
FreeSWITCH-users mailing list
FreeSWITCH-users@lists.freeswitch.org
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org