I using freeswitch webrtc version (1.4) and webrtc android (apprtc) and jssip. In that when i make call from android apprtc to jssip, i have audio both way and its fine . but when i make call from jssip to android apprtc , i am not having audio. in android libjingel i can see log that timing out Stun ping. i checked in freeswitch server using tcpdump freeswitch getting rtp packet from android but freeswitch didn`t send any rtp packet to android. freeswitch and jssip have rtp packet flow in both way. jssip -> android apprtc (invite in android logcat) ------------------------- o=FreeSWITCH 1385973198 1385973199 IN IP4 xx.xx.xx.xx s=FreeSWITCH c=IN IP4 xx.xx.xx.xx t=0 0 a=sendrecv a=msid-semantic: WMS UlOyQ5IJeQTym7lcjsHwF8OVnhalote9 m=audio 20966 RTP/SAVPF 0 8 101 13 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fingerprint:sha-256 91:9E:50:FA:2E:A5:8E:02:41:1E:FC:A5:8A:B0:0C:1F:98:1F:1B:49:BB:D6:44:A8:E1:01:EA:82:7C:B6:59:1D a=rtcp-mux a=rtcp:20966 IN IP4 xx.xx.xx.xx a=ssrc:2057333412 cname:FTymO6VTNEh0Ct3L a=ssrc:2057333412 msid:UlOyQ5IJeQTym7lcjsHwF8OVnhalote9 a0 a=ssrc:2057333412 mslabel:UlOyQ5IJeQTym7lcjsHwF8OVnhalote9 a=ssrc:2057333412 label:UlOyQ5IJeQTym7lcjsHwF8OVnhalote9a0 a=ice-ufrag:LB8hzN2MU3Y9n38T a=ice-pwd:Mw5qtQa7liXOBQpd a=candidate:6185949872 1 udp 659136 xx.xx.xx.xx 20966 typ host generation 0 a=candidate:6185949872 2 udp 659136 xx.xx.xx.xx 20966 typ host generation 0 a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:bY3YaWkQ5/2oKz9gEKtNKKF8ovPs7nIVWIUmHzuF a=ptime:20 jssip <-- android apprtc (200 ok in android logcat) ------------------------- v=0 o=- 439041227922934440 2 IN IP4 127.0.0.1 s=- t=0 0 a=msid-semantic: WMS m=audio 15144 RTP/SAVPF 0 8 13 101 c=IN IP4 115.111.5.34 a=rtcp:1 IN IP4 0.0.0.0 a=candidate:622902765 1 udp 2113937151 xx.xx.xx.xx 35848 typ host generation 0 a=candidate:1739408229 1 udp 1845501695 115.111.5.34 15144 typ srflx raddr xx.xx.xx.xx rport 35848 generation 0 a=candidate:1805861149 1 tcp 1509957375 xx.xx.xx.xx 56537 typ host generation 0 a=ice-ufrag:smxJUV1NajVUJMij a=ice-pwd:bNv1nkF5MB2MTQGUGtCKxt5U a=mid:audio a=sendrecv a=rtcp-mux a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:jdpxXuVNsf3V9gIQr+bcmzPO1Z+3gUzwkImHP/fL a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:13 CN/8000 a=rtpmap:101 telephone-event/8000 a=candidate:622902765 1 udp 2113937151 xx.xx.xx.xx 35848 typ host generation 0 a=candidate:1739408229 1 udp 1845501695 xx.xx.xx.xx 15144 typ srflx raddr xx.xx.xx.xx rport 35848 generation 0 a=candidate:1805861149 1 tcp 1509957375 xx.xx.xx.xx 56537 typ host generation 0 freeswitch log for call from jssip to android ------------------------------------------------- 2013-12-02 15:11:49.078540 [NOTICE] switch_channel.c:1055 New Channel sofia/internal/111998@xx.xx.xx.xx [b474f6b8-113f-4208-aa4e-b3c270be9c16] 2013-12-02 15:11:49.078540 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/111998@xx.xx.xx.xx [BREAK] 2013-12-02 15:11:49.078540 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/111998@xx.xx.xx.xx [BREAK] 2013-12-02 15:11:49.078540 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/111998@xx.xx.xx.xx) Running State Change CS_NEW 2013-12-02 15:11:49.078540 [DEBUG] switch_core_state_machine.c:485 (sofia/internal/111998@xx.xx.xx.xx) State NEW 2013-12-02 15:11:49.098544 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/111998@xx.xx.xx.xx [BREAK] 2013-12-02 15:11:49.098544 [DEBUG] sofia.c:1816 detaching session b474f6b8-113f-4208-aa4e-b3c270be9c16 2013-12-02 15:11:49.638540 [DEBUG] sofia.c:1908 Re-attaching to session b474f6b8-113f-4208-aa4e-b3c270be9c16 2013-12-02 15:11:49.638540 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/111998@xx.xx.xx.xx [BREAK] 2013-12-02 15:11:49.638540 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/111998@xx.xx.xx.xx [BREAK] 2013-12-02 15:11:49.658540 [DEBUG] sofia.c:9117 Setting NAT mode based on websockets 2013-12-02 15:11:49.658540 [DEBUG] sofia.c:5861 Channel sofia/internal/111998@xx.xx.xx.xx entering state [received][100] 2013-12-02 15:11:49.658540 [DEBUG] sofia.c:5871 Remote SDP: v=0 o=- 7956339218042656413 2 IN IP4 127.0.0.1 s=- t=0 0 a=group:BUNDLE audio a=msid-semantic: WMS M7kcmbQB5jHLGFt0kHsc02lJG5UNnWJUd3ur m=audio 52606 RTP/SAVPF 111 103 104 0 8 106 105 13 126 c=IN IP4 xx.xx.xx.xx a=rtpmap:111 opus/48000/2 a=fmtp:111 minptime=10 a=rtpmap:103 ISAC/16000 a=rtpmap:104 ISAC/32000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:106 CN/32000 a=rtpmap:105 CN/16000 a=rtpmap:13 CN/8000 a=rtpmap:126 telephone-event/8000 a=rtcp:52606 IN IP4 xx.xx.xx.xx a=candidate:3052889280 1 udp 2113937151 10.4.5.177 63907 typ host generation 0 a=candidate:3052889280 2 udp 2113937151 10.4.5.177 63907 typ host generation 0 a=candidate:4218722352 1 tcp 1509957375 10.4.5.177 0 typ host generation 0 a=candidate:4218722352 2 tcp 1509957375 10.4.5.177 0 typ host generation 0 a=candidate:1456923180 1 udp 1845501695 xx.xx.xx.xx 52606 typ srflx raddr 10.4.5.177 rport 63907 generation 0 a=candidate:1456923180 2 udp 1845501695 xx.xx.xx.xx 52606 typ srflx raddr 10.4.5.177 rport 63907 generation 0 a=ice-ufrag:fNi6w7SNINs91kf1 a=ice-pwd:xi64ann1iU6AYNvBh9m9bLVl a=ice-options:google-ice a=fingerprint:sha-256 E7:B9:4B:22:20:C9:67:BD:FE:B2:5A:01:17:F4:6B:3A:C4:04:20:53:C2:0A:F0:5C:98:22:4D:C9:C8:60:14:EB a=setup:actpass a=mid:audio a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level a=rtcp-mux a=crypto:0 AES_CM_128_HMAC_SHA1_32 inline:os2etUzJazzxo5/mG0SMitAVZrSUdxFIDgxr1dK8 a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:WVqrcslWrYWs1a8DDUI4/ahkq0xJ6FweRd/0xJZr a=maxptime:60 a=ssrc:2810925229 cname:Vkbzh4QSGqv02wU4 a=ssrc:2810925229 msid:M7kcmbQB5jHLGFt0kHsc02lJG5UNnWJUd3ur M7kcmbQB5jHLGFt0kHsc02lJG5UNnWJUd3ura0 a=ssrc:2810925229 mslabel:M7kcmbQB5jHLGFt0kHsc02lJG5UNnWJUd3ur a=ssrc:2810925229 label:M7kcmbQB5jHLGFt0kHsc02lJG5UNnWJUd3ura0 2013-12-02 15:11:49.658540 [DEBUG] sofia.c:6116 (sofia/internal/111998@xx.xx.xx.xx) State Change CS_NEW -> CS_INIT 2013-12-02 15:11:49.658540 [DEBUG] switch_core_session.c:1374 Send signal sofia/internal/111998@xx.xx.xx.xx [BREAK] 2013-12-02 15:11:49.658540 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/111998@xx.xx.xx.xx) Running State Change CS_INIT 2013-12-02 15:11:49.658540 [DEBUG] switch_core_state_machine.c:506 (sofia/internal/111998@xx.xx.xx.xx) State INIT 2013-12-02 15:11:49.658540 [DEBUG] mod_sofia.c:87 sofia/internal/111998@xx.xx.xx.xx SOFIA INIT 2013-12-02 15:11:49.658540 [DEBUG] switch_core_state_machine.c:40 sofia/internal/111998@xx.xx.xx.xx Standard INIT 2013-12-02 15:11:49.658540 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/111998@xx.xx.xx.xx) State Change CS_INIT -> CS_ROUTING 2013-12-02 15:11:49.658540 [DEBUG] switch_core_session.c:1374 Send signal sofia/internal/111998@xx.xx.xx.xx [BREAK] 2013-12-02 15:11:49.658540 [DEBUG] switch_core_state_machine.c:506 (sofia/internal/111998@xx.xx.xx.xx) State INIT going to sleep 2013-12-02 15:11:49.658540 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/111998@xx.xx.xx.xx) Running State Change CS_ROUTING 2013-12-02 15:11:49.658540 [DEBUG] switch_channel.c:2178 (sofia/internal/111998@xx.xx.xx.xx) Callstate Change DOWN -> RINGING 2013-12-02 15:11:49.658540 [DEBUG] switch_core_state_machine.c:522 (sofia/internal/111998@xx.xx.xx.xx) State ROUTING 2013-12-02 15:11:49.658540 [DEBUG] mod_sofia.c:123 sofia/internal/111998@xx.xx.xx.xx SOFIA ROUTING 2013-12-02 15:11:49.658540 [DEBUG] switch_core_state_machine.c:164 sofia/internal/111998@xx.xx.xx.xx Standard ROUTING 2013-12-02 15:11:49.658540 [INFO] mod_dialplan_xml.c:558 Processing 111998 <111998>->111999 in context default Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->tod_example] continue=true Dialplan: sofia/internal/111998@xx.xx.xx.xx Date/Time Match (PASS) [tod_example] break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx Action set(open=true) Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->holiday_example] continue=true Dialplan: sofia/internal/111998@xx.xx.xx.xx Date/TimeMatch (FAIL) [holiday_example] break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->global-intercept] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [global-intercept] destination_number(111999) =~ /^886$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->group-intercept] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [group-intercept] destination_number(111999) =~ /^\*8$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->intercept-ext] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [intercept-ext] destination_number(111999) =~ /^\*\*(\d+)$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->redial] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [redial] destination_number(111999) =~ /^(redial|870)$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->global] continue=true Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [global] ${rtp_has_crypto}() =~ /^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$/ break=never Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (PASS) [global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (PASS) [global] ${switch_r_sdp}(v=0 o=- 7956339218042656413 2 IN IP4 127.0.0.1 s=- t=0 0 a=group:BUNDLE audio a=msid-semantic: WMS M7kcmbQB5jHLGFt0kHsc02lJG5UNnWJUd3ur m=audio 52606 RTP/SAVPF 111 103 104 0 8 106 105 13 126 c=IN IP4 xx.xx.xx.xx a=rtpmap:111 opus/48000/2 a=fmtp:111 minptime=10 a=rtpmap:103 ISAC/16000 a=rtpmap:104 ISAC/32000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:106 CN/32000 a=rtpmap:105 CN/16000 a=rtpmap:13 CN/8000 a=rtpmap:126 telephone-event/8000 a=rtcp:52606 IN IP4 xx.xx.xx.xx a=candidate:3052889280 1 udp 2113937151 10.4.5.177 63907 typ host generation 0 a=candidate:3052889280 2 udp 2113937151 10.4.5.177 63907 typ host generation 0 a=candidate:4218722352 1 tcp 1509957375 10.4.5.177 0 typ host generation 0 a=candidate:4218722352 2 tcp 1509957375 10.4.5.177 0 typ host generation 0 a=candidate:1456923180 1 udp 1845501695 xx.xx.xx.xx 52606 typ srflx raddr 10.4.5.177 rport 63907 generation 0 a=candidate:1456923180 2 udp 1845501695 xx.xx.xx.xx 52606 typ srflx raddr 10.4.5.177 rport 63907 generation 0 a=ice-ufrag:fNi6w7SNINs91kf1 a=ice-pwd:xi64ann1iU6AYNvBh9m9bLVl a=ice-options:google-ice a=fingerprint:sha-256 E7:B9:4B:22:20:C9:67:BD:FE:B2:5A:01:17:F4:6B:3A:C4:04:20:53:C2:0A:F0:5C:98:22:4D:C9:C8:60:14:EB a=setup:actpass a=mid:audio a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level a=rtcp-mux a=crypto:0 AES_CM_128_HMAC_SHA1_32 inline:os2etUzJazzxo5/mG0SMitAVZrSUdxFIDgxr1dK8 a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:WVqrcslWrYWs1a8DDUI4/ahkq0xJ6FweRd/0xJZr a=maxptime:60 a=ssrc:2810925229 cname:Vkbzh4QSGqv02wU4 a=ssrc:2810925229 msid:M7kcmbQB5jHLGFt0kHsc02lJG5UNnWJUd3ur M7kcmbQB5jHLGFt0kHsc02lJG5UNnWJUd3ura0 a=ssrc:2810925229 mslabel:M7kcmbQB5jHLGFt0kHsc02lJG5UNnWJUd3ur a=ssrc:2810925229 label:M7kcmbQB5jHLGFt0kHsc02lJG5UNnWJUd3ura0 ) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never Dialplan: sofia/internal/111998@xx.xx.xx.xx Action set(rtp_secure_media=true) Dialplan: sofia/internal/111998@xx.xx.xx.xx Absolute Condition [global] Dialplan: sofia/internal/111998@xx.xx.xx.xx Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: sofia/internal/111998@xx.xx.xx.xx Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: sofia/internal/111998@xx.xx.xx.xx Action hash(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: sofia/internal/111998@xx.xx.xx.xx Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->snom-demo-2] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [snom-demo-2] destination_number(111999) =~ /^9001$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->snom-demo-1] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [snom-demo-1] destination_number(111999) =~ /^9000$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [eavesdrop] destination_number(111999) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [eavesdrop] destination_number(111999) =~ /^779$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->call_return] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [call_return] destination_number(111999) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->del-group] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [del-group] destination_number(111999) =~ /^80(\d{2})$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->add-group] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [add-group] destination_number(111999) =~ /^81(\d{2})$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->call-group-simo] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [call-group-simo] destination_number(111999) =~ /^82(\d{2})$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->call-group-order] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [call-group-order] destination_number(111999) =~ /^83(\d{2})$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->extension-intercom] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [extension-intercom] destination_number(111999) =~ /^8(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->Local_Extension] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [Local_Extension] destination_number(111999) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->Local_Extension_Skinny] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [Local_Extension_Skinny] destination_number(111999) =~ /^(11[01][0-9])$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->group_dial_sales] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [group_dial_sales] destination_number(111999) =~ /^2000$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->group_dial_support] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [group_dial_support] destination_number(111999) =~ /^2001$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->group_dial_billing] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [group_dial_billing] destination_number(111999) =~ /^2002$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->operator] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [operator] destination_number(111999) =~ /^(operator|0)$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->vmain] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [vmain] destination_number(111999) =~ /^vmain$|^4000$|^\*98$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->sip_uri] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [sip_uri] destination_number(111999) =~ /^sip:(.*)$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->nb_conferences] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [nb_conferences] destination_number(111999) =~ /^(30\d{2})$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->wb_conferences] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [wb_conferences] destination_number(111999) =~ /^(31\d{2})$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->uwb_conferences] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [uwb_conferences] destination_number(111999) =~ /^(32\d{2})$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->cdquality_conferences] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [cdquality_conferences] destination_number(111999) =~ /^(33\d{2})$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->freeswitch_public_conf_via_sip] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [freeswitch_public_conf_via_sip] destination_number(111999) =~ /^9(888|8888|1616|3232)$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->mad_boss_intercom] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [mad_boss_intercom] destination_number(111999) =~ /^0911$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->mad_boss_intercom] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [mad_boss_intercom] destination_number(111999) =~ /^0912$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->mad_boss] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [mad_boss] destination_number(111999) =~ /^0913$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->ivr_demo] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [ivr_demo] destination_number(111999) =~ /^5000$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->dynamic_conference] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [dynamic_conference] destination_number(111999) =~ /^5001$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->rtp_multicast_page] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [rtp_multicast_page] destination_number(111999) =~ /^pagegroup$|^7243$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->park] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [park] destination_number(111999) =~ /^5900$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->unpark] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [unpark] destination_number(111999) =~ /^5901$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->valet_park] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [valet_park] destination_number(111999) =~ /^(6000)$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->valet_park] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [valet_park] destination_number(111999) =~ /^(60\d[1-9])$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->park] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (PASS) [park] source(mod_sofia) =~ /mod_sofia/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [park] destination_number(111999) =~ /park\+(\d+)/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->unpark] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (PASS) [unpark] source(mod_sofia) =~ /mod_sofia/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [unpark] destination_number(111999) =~ /^parking$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->park] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (PASS) [park] source(mod_sofia) =~ /mod_sofia/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [park] destination_number(111999) =~ /callpark/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->unpark] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (PASS) [unpark] source(mod_sofia) =~ /mod_sofia/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [unpark] destination_number(111999) =~ /pickup/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->wait] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [wait] destination_number(111999) =~ /^wait$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->fax_receive] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [fax_receive] destination_number(111999) =~ /^9178$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->fax_transmit] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [fax_transmit] destination_number(111999) =~ /^9179$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->ringback_180] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [ringback_180] destination_number(111999) =~ /^9180$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->ringback_183_uk_ring] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [ringback_183_uk_ring] destination_number(111999) =~ /^9181$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->ringback_183_music_ring] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [ringback_183_music_ring] destination_number(111999) =~ /^9182$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->ringback_post_answer_uk_ring] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [ringback_post_answer_uk_ring] destination_number(111999) =~ /^9183$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->ringback_post_answer_music] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [ringback_post_answer_music] destination_number(111999) =~ /^9184$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->ClueCon] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [ClueCon] destination_number(111999) =~ /^9191$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->show_info] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [show_info] destination_number(111999) =~ /^9192$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->video_record] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [video_record] destination_number(111999) =~ /^9193$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->video_playback] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [video_playback] destination_number(111999) =~ /^9194$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->delay_echo] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [delay_echo] destination_number(111999) =~ /^9195$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->echo] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [echo] destination_number(111999) =~ /^9196$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->milliwatt] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [milliwatt] destination_number(111999) =~ /^9197$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->tone_stream] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [tone_stream] destination_number(111999) =~ /^9198$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->zrtp_enrollement] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [zrtp_enrollement] destination_number(111999) =~ /^9787$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->hold_music] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [hold_music] destination_number(111999) =~ /^9664$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->laugh break] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [laugh break] destination_number(111999) =~ /^9386$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->101] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [101] destination_number(111999) =~ /^101$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->pizza_demo] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [pizza_demo] destination_number(111999) =~ /^(pizza|74992)$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->Talking Clock Time] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [Talking Clock Time] destination_number(111999) =~ /^9170$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->Talking Clock Date] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [Talking Clock Date] destination_number(111999) =~ /^9171$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->Talking Clock Date and Time] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [Talking Clock Date and Time] destination_number(111999) =~ /^9172$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->local2.example.com] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (PASS) [local2.example.com] ${toll_allow}(domestic,international,local) =~ /local/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [local2.example.com] destination_number(111999) =~ /^(\d{7})$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->domestic2.example.com] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (PASS) [domestic2.example.com] ${toll_allow}(domestic,international,local) =~ /domestic/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [domestic2.example.com] destination_number(111999) =~ /^(\d{1})$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->international2.example.com] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (PASS) [international2.example.com] ${toll_allow}(domestic,international,local) =~ /international/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [international2.example.com] destination_number(111999) =~ /^(011\d+)$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->bandwidth.com Outbound 9.10d] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [bandwidth.com Outbound 9.10d] destination_number(111999) =~ /^\+1(\d{10})$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->Outbound_Extension_custom] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (FAIL) [Outbound_Extension_custom] destination_number(111999) =~ /^1(\d{10})$/ break=never Dialplan: sofia/internal/111998@xx.xx.xx.xx parsing [default->Local_Extension_custom] continue=false Dialplan: sofia/internal/111998@xx.xx.xx.xx Regex (PASS) [Local_Extension_custom] destination_number(111999) =~ /^([19][0129][0-9][0-9][0-9][0-9]?)$/ break=on-false Dialplan: sofia/internal/111998@xx.xx.xx.xx Action export(nolocal:absolute_codec_string=PCMU,PCMA) Dialplan: sofia/internal/111998@xx.xx.xx.xx Action export(media_webrtc=true) Dialplan: sofia/internal/111998@xx.xx.xx.xx Action export(dialed_extension=111999) Dialplan: sofia/internal/111998@xx.xx.xx.xx Action set(ringback=${us-ring}) Dialplan: sofia/internal/111998@xx.xx.xx.xx Action set(transfer_ringback=local_stream://moh) Dialplan: sofia/internal/111998@xx.xx.xx.xx Action set(call_timeout=30) Dialplan: sofia/internal/111998@xx.xx.xx.xx Action set(hangup_after_bridge=true) Dialplan: sofia/internal/111998@xx.xx.xx.xx Action set(continue_on_fail=true) Dialplan: sofia/internal/111998@xx.xx.xx.xx Action bridge(user/${dialed_extension}@${domain_name}) Dialplan: sofia/internal/111998@xx.xx.xx.xx Action answer() Dialplan: sofia/internal/111998@xx.xx.xx.xx Action sleep(1000) Dialplan: sofia/internal/111998@xx.xx.xx.xx Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension}) 2013-12-02 15:11:49.658540 [DEBUG] switch_core_state_machine.c:214 (sofia/internal/111998@xx.xx.xx.xx) State Change CS_ROUTING -> CS_EXECUTE 2013-12-02 15:11:49.658540 [DEBUG] switch_core_session.c:1374 Send signal sofia/internal/111998@xx.xx.xx.xx [BREAK] 2013-12-02 15:11:49.658540 [DEBUG] switch_core_state_machine.c:522 (sofia/internal/111998@xx.xx.xx.xx) State ROUTING going to sleep 2013-12-02 15:11:49.658540 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/111998@xx.xx.xx.xx) Running State Change CS_EXECUTE 2013-12-02 15:11:49.658540 [DEBUG] switch_core_state_machine.c:529 (sofia/internal/111998@xx.xx.xx.xx) State EXECUTE 2013-12-02 15:11:49.658540 [DEBUG] mod_sofia.c:178 sofia/internal/111998@xx.xx.xx.xx SOFIA EXECUTE 2013-12-02 15:11:49.658540 [DEBUG] switch_core_state_machine.c:256 sofia/internal/111998@xx.xx.xx.xx Standard EXECUTE EXECUTE sofia/internal/111998@xx.xx.xx.xx set(open=true) 2013-12-02 15:11:49.658540 [DEBUG] mod_dptools.c:1402 sofia/internal/111998@xx.xx.xx.xx SET [open]=[true] EXECUTE sofia/internal/111998@xx.xx.xx.xx set(rtp_secure_media=true) 2013-12-02 15:11:49.658540 [DEBUG] mod_dptools.c:1402 sofia/internal/111998@xx.xx.xx.xx SET [rtp_secure_media]=[true] EXECUTE sofia/internal/111998@xx.xx.xx.xx hash(insert/10.188.136.13-spymap/111998/b474f6b8-113f-4208-aa4e-b3c270be9c16) EXECUTE sofia/internal/111998@xx.xx.xx.xx hash(insert/10.188.136.13-last_dial/111998/111999) EXECUTE sofia/internal/111998@xx.xx.xx.xx hash(insert/10.188.136.13-last_dial/global/b474f6b8-113f-4208-aa4e-b3c270be9c16) EXECUTE sofia/internal/111998@xx.xx.xx.xx export(RFC2822_DATE=Mon, 02 Dec 2013 15:11:49 +0000) 2013-12-02 15:11:49.658540 [DEBUG] switch_channel.c:1247 EXPORT (export_vars) [RFC2822_DATE]=[Mon, 02 Dec 2013 15:11:49 +0000] EXECUTE sofia/internal/111998@xx.xx.xx.xx export(nolocal:absolute_codec_string=PCMU,PCMA) 2013-12-02 15:11:49.658540 [DEBUG] switch_channel.c:1247 EXPORT (export_vars) (REMOTE ONLY) [absolute_codec_string]=[PCMU,PCMA] EXECUTE sofia/internal/111998@xx.xx.xx.xx export(media_webrtc=true) 2013-12-02 15:11:49.658540 [DEBUG] switch_channel.c:1247 EXPORT (export_vars) [media_webrtc]=[true] EXECUTE sofia/internal/111998@xx.xx.xx.xx export(dialed_extension=111999) 2013-12-02 15:11:49.658540 [DEBUG] switch_channel.c:1247 EXPORT (export_vars) [dialed_extension]=[111999] EXECUTE sofia/internal/111998@xx.xx.xx.xx set(ringback=%(2000,4000,440,480)) 2013-12-02 15:11:49.658540 [DEBUG] mod_dptools.c:1402 sofia/internal/111998@xx.xx.xx.xx SET [ringback]=[%(2000,4000,440,480)] EXECUTE sofia/internal/111998@xx.xx.xx.xx set(transfer_ringback=local_stream://moh) 2013-12-02 15:11:49.658540 [DEBUG] mod_dptools.c:1402 sofia/internal/111998@xx.xx.xx.xx SET [transfer_ringback]=[local_stream://moh] EXECUTE sofia/internal/111998@xx.xx.xx.xx set(call_timeout=30) 2013-12-02 15:11:49.658540 [DEBUG] mod_dptools.c:1402 sofia/internal/111998@xx.xx.xx.xx SET [call_timeout]=[30] EXECUTE sofia/internal/111998@xx.xx.xx.xx set(hangup_after_bridge=true) 2013-12-02 15:11:49.658540 [DEBUG] mod_dptools.c:1402 sofia/internal/111998@xx.xx.xx.xx SET [hangup_after_bridge]=[true] EXECUTE sofia/internal/111998@xx.xx.xx.xx set(continue_on_fail=true) 2013-12-02 15:11:49.658540 [DEBUG] mod_dptools.c:1402 sofia/internal/111998@xx.xx.xx.xx SET [continue_on_fail]=[true] EXECUTE sofia/internal/111998@xx.xx.xx.xx bridge(user/111999@10.188.136.13) 2013-12-02 15:11:49.658540 [DEBUG] switch_channel.c:1201 sofia/internal/111998@xx.xx.xx.xx EXPORTING[export_vars] [RFC2822_DATE]=[Mon, 02 Dec 2013 15:11:49 +0000] to event 2013-12-02 15:11:49.658540 [DEBUG] switch_channel.c:1201 sofia/internal/111998@xx.xx.xx.xx EXPORTING[export_vars] [absolute_codec_string]=[PCMU,PCMA] to event 2013-12-02 15:11:49.658540 [DEBUG] switch_channel.c:1201 sofia/internal/111998@xx.xx.xx.xx EXPORTING[export_vars] [media_webrtc]=[true] to event 2013-12-02 15:11:49.658540 [DEBUG] switch_channel.c:1201 sofia/internal/111998@xx.xx.xx.xx EXPORTING[export_vars] [dialed_extension]=[111999] to event 2013-12-02 15:11:49.658540 [DEBUG] switch_ivr_originate.c:2070 Parsing global variables 2013-12-02 15:11:49.658540 [DEBUG] switch_channel.c:1201 sofia/internal/111998@xx.xx.xx.xx EXPORTING[export_vars] [RFC2822_DATE]=[Mon, 02 Dec 2013 15:11:49 +0000] to event 2013-12-02 15:11:49.658540 [DEBUG] switch_channel.c:1201 sofia/internal/111998@xx.xx.xx.xx EXPORTING[export_vars] [absolute_codec_string]=[PCMU,PCMA] to event 2013-12-02 15:11:49.658540 [DEBUG] switch_channel.c:1201 sofia/internal/111998@xx.xx.xx.xx EXPORTING[export_vars] [media_webrtc]=[true] to event 2013-12-02 15:11:49.658540 [DEBUG] switch_channel.c:1201 sofia/internal/111998@xx.xx.xx.xx EXPORTING[export_vars] [dialed_extension]=[111999] to event 2013-12-02 15:11:49.658540 [DEBUG] switch_ivr_originate.c:2070 Parsing global variables 2013-12-02 15:11:49.658540 [DEBUG] switch_event.c:1680 Parsing variable [sip_invite_domain]=[10.188.136.13] 2013-12-02 15:11:49.658540 [DEBUG] switch_event.c:1680 Parsing variable [presence_id]=[111999@10.188.136.13] 2013-12-02 15:11:49.658540 [NOTICE] switch_channel.c:1055 New Channel sofia/internal/sip:111999@xx.xx.xx.xx:48336 [9417c8d2-78e4-47cf-8c22-1718cbd744ba] 2013-12-02 15:11:49.658540 [DEBUG] mod_sofia.c:4429 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) State Change CS_NEW -> CS_INIT 2013-12-02 15:11:49.658540 [DEBUG] switch_core_session.c:1374 Send signal sofia/internal/sip:111999@xx.xx.xx.xx:48336 [BREAK] 2013-12-02 15:11:49.658540 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) Running State Change CS_INIT 2013-12-02 15:11:49.658540 [DEBUG] switch_core_state_machine.c:506 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) State INIT 2013-12-02 15:11:49.658540 [DEBUG] mod_sofia.c:87 sofia/internal/sip:111999@xx.xx.xx.xx:48336 SOFIA INIT 2013-12-02 15:11:49.658540 [DEBUG] switch_core_media.c:866 Set Local Key [1 AES_CM_128_HMAC_SHA1_80 inline:woQ+Cv8cMzy2AcEgTaPMNHWVUBq5M1JgIbdd/rWY] 2013-12-02 15:11:49.658540 [DEBUG] switch_core_media.c:866 Set Local Key [1 AES_CM_128_HMAC_SHA1_80 inline:8eNzTa4apnPAZcK2707EPIAUR/Z85E6WcnwhM24H] 2013-12-02 15:11:49.658540 [DEBUG] switch_core_media.c:5921 JAMES WAS HERE : isendrecv . 2013-12-02 15:11:49.658540 [DEBUG] sofia_glue.c:1196 sip:111999@xx.xx.xx.xx:48336;transpo;lr;ovid=c5ab5428 Setting proxy route to sofia/internal/sip:111999@xx.xx.xx.xx:48336 2013-12-02 15:11:49.658540 [DEBUG] sofia_glue.c:1225 Local SDP: v=0 o=FreeSWITCH 1385966477 1385966478 IN IP4 xx.xx.xx.xx s=FreeSWITCH c=IN IP4 xx.xx.xx.xx t=0 0 a=sendrecv a=msid-semantic: WMS yltseQwRXjj4V9bL1UFJklt5Y8F6ME9a m=audio 30632 RTP/SAVPF 0 8 101 13 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fingerprint:sha-256 91:9E:50:FA:2E:A5:8E:02:41:1E:FC:A5:8A:B0:0C:1F:98:1F:1B:49:BB:D6:44:A8:E1:01:EA:82:7C:B6:59:1D a=rtcp-mux a=rtcp:30632 IN IP4 xx.xx.xx.xx a=ssrc:2057233717 cname:QssU8OBWYLQJKRkC a=ssrc:2057233717 msid:yltseQwRXjj4V9bL1UFJklt5Y8F6ME9a a0 a=ssrc:2057233717 mslabel:yltseQwRXjj4V9bL1UFJklt5Y8F6ME9a a=ssrc:2057233717 label:yltseQwRXjj4V9bL1UFJklt5Y8F6ME9aa0 a=ice-ufrag:CQbM1vIQtdM6IM6o a=ice-pwd:4p833AQSbxrMeCeH a=candidate:7396588577 1 udp 659136 xx.xx.xx.xx 30632 typ host generation 0 a=candidate:7396588577 2 udp 659136 xx.xx.xx.xx 30632 typ host generation 0 a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:woQ+Cv8cMzy2AcEgTaPMNHWVUBq5M1JgIbdd/rWY a=ptime:20 2013-12-02 15:11:49.658540 [DEBUG] switch_core_state_machine.c:40 sofia/internal/sip:111999@xx.xx.xx.xx:48336 Standard INIT 2013-12-02 15:11:49.658540 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) State Change CS_INIT -> CS_ROUTING 2013-12-02 15:11:49.658540 [DEBUG] switch_core_session.c:1374 Send signal sofia/internal/sip:111999@xx.xx.xx.xx:48336 [BREAK] 2013-12-02 15:11:49.658540 [DEBUG] switch_core_state_machine.c:506 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) State INIT going to sleep 2013-12-02 15:11:49.658540 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) Running State Change CS_ROUTING 2013-12-02 15:11:49.658540 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/sip:111999@xx.xx.xx.xx:48336 [BREAK] 2013-12-02 15:11:49.658540 [DEBUG] switch_core_state_machine.c:522 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) State ROUTING 2013-12-02 15:11:49.658540 [DEBUG] mod_sofia.c:123 sofia/internal/sip:111999@xx.xx.xx.xx:48336 SOFIA ROUTING 2013-12-02 15:11:49.658540 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2013-12-02 15:11:49.658540 [DEBUG] switch_core_session.c:1374 Send signal sofia/internal/sip:111999@xx.xx.xx.xx:48336 [BREAK] 2013-12-02 15:11:49.658540 [DEBUG] switch_core_state_machine.c:522 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) State ROUTING going to sleep 2013-12-02 15:11:49.658540 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) Running State Change CS_CONSUME_MEDIA 2013-12-02 15:11:49.658540 [DEBUG] switch_core_state_machine.c:541 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) State CONSUME_MEDIA 2013-12-02 15:11:49.658540 [DEBUG] switch_core_state_machine.c:541 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) State CONSUME_MEDIA going to sleep 2013-12-02 15:11:49.658540 [DEBUG] sofia.c:5861 Channel sofia/internal/sip:111999@xx.xx.xx.xx:48336 entering state [calling][0] 2013-12-02 15:11:50.478540 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/sip:111999@xx.xx.xx.xx:48336 [BREAK] 2013-12-02 15:11:50.478540 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/sip:111999@xx.xx.xx.xx:48336 [BREAK] 2013-12-02 15:11:50.498554 [DEBUG] sofia.c:5861 Channel sofia/internal/sip:111999@xx.xx.xx.xx:48336 entering state [proceeding][180] 2013-12-02 15:11:50.498554 [DEBUG] sofia.c:5871 Remote SDP: v=0 o=- 751491027366329237 2 IN IP4 127.0.0.1 s=- t=0 0 a=msid-semantic: WMS m=audio 15561 RTP/SAVPF 0 8 13 101 c=IN IP4 xx.xx.xx.xx a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:13 CN/8000 a=rtpmap:101 telephone-event/8000 a=rtcp:1 IN IP4 0.0.0.0 a=candidate:622902765 1 udp 2113937151 xx.xx.xx.xx 41736 typ host generation 0 a=candidate:1805861149 1 tcp 1509957375 xx.xx.xx.xx 49160 typ host generation 0 a=candidate:1739408229 1 udp 1845501695 xx.xx.xx.xx 15561 typ srflx raddr xx.xx.xx.xx rport 41736 generation 0 a=ice-ufrag:mbtnHm5KfkZqEDnI a=ice-pwd:nA2j+Sq8+sF/DnCRucATdnDd a=mid:audio a=rtcp-mux a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:sULSASTq8o0rKq0N+g5LHr4bCcdMFXHsXjQ5ijLK a=candidate:622902765 1 udp 2113937151 xx.xx.xx.xx 41736 typ host generation 0 a=candidate:1805861149 1 tcp 1509957375 xx.xx.xx.xx 49160 typ host generation 0 a=candidate:1739408229 1 udp 1845501695 xx.xx.xx.xx 15561 typ srflx raddr xx.xx.xx.xx rport 41736 generation 0 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:1065 Set Remote Key [1 AES_CM_128_HMAC_SHA1_80 inline:sULSASTq8o0rKq0N+g5LHr4bCcdMFXHsXjQ5ijLK] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3213 Audio Codec Compare [PCMU:0:8000:20:64000] ++++ is saved as a match 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMA:8:8000:20:64000] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMU:0:8000:20:64000] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMA:8:8000:20:64000] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3213 Audio Codec Compare [PCMA:8:8000:20:64000] ++++ is saved as a match 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3085 Set telephone-event payload to 101 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:2123 Set Codec sofia/internal/sip:111999@xx.xx.xx.xx:48336 PCMU/8000 20 ms 160 samples 64000 bits 2013-12-02 15:11:50.498554 [DEBUG] switch_core_codec.c:111 sofia/internal/sip:111999@xx.xx.xx.xx:48336 Original read codec set to PCMU:0 2013-12-02 15:11:50.498554 [WARNING] switch_core_media.c:2324 NO candidate ACL defined, Defaulting to wan.auto 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:2348 Checking Candidate cid: 1 proto: udp type: host addr: xx.xx.xx.xx:41736 2013-12-02 15:11:50.498554 [NOTICE] switch_core_media.c:2362 Save audio Candidate cid: 1 proto: udp type: host addr: xx.xx.xx.xx:41736 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:2348 Checking Candidate cid: 1 proto: udp type: srflx addr: xx.xx.xx.xx:15561 2013-12-02 15:11:50.498554 [NOTICE] switch_core_media.c:2357 Choose audio Candidate cid: 1 proto: udp type: srflx addr: xx.xx.xx.xx:15561 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:2348 Checking Candidate cid: 1 proto: udp type: host addr: xx.xx.xx.xx:41736 2013-12-02 15:11:50.498554 [NOTICE] switch_core_media.c:2362 Save audio Candidate cid: 1 proto: udp type: host addr: xx.xx.xx.xx:41736 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:2348 Checking Candidate cid: 1 proto: udp type: srflx addr: xx.xx.xx.xx:15561 2013-12-02 15:11:50.498554 [NOTICE] switch_core_media.c:2362 Save audio Candidate cid: 1 proto: udp type: srflx addr: xx.xx.xx.xx:15561 2013-12-02 15:11:50.498554 [NOTICE] switch_core_media.c:2451 No audio RTCP candidate found; defaulting to the same as RTP [xx.xx.xx.xx:15561] 2013-12-02 15:11:50.498554 [NOTICE] switch_core_media.c:2486 setting remote audio ice addr to xx.xx.xx.xx:15561 based on candidate 2013-12-02 15:11:50.498554 [NOTICE] switch_core_media.c:2506 setting remote rtcp audio addr to xx.xx.xx.xx:15561 based on candidate 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3382 Set 2833 dtmf send payload to 101 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:4563 AUDIO RTP [sofia/internal/sip:111999@xx.xx.xx.xx:48336] 10.188.136.13 port 30632 -> xx.xx.xx.xx port 15561 codec: 0 ms: 20 2013-12-02 15:11:50.498554 [DEBUG] switch_rtp.c:3047 Starting timer [soft] 160 bytes per 20ms 2013-12-02 15:11:50.498554 [INFO] switch_core_media.c:4732 Activating Audio ICE 2013-12-02 15:11:50.498554 [NOTICE] switch_rtp.c:3474 Activating RTP audio ICE: mbtnHm5KfkZqEDnI:CQbM1vIQtdM6IM6o xx.xx.xx.xx:15561 2013-12-02 15:11:50.498554 [INFO] switch_core_media.c:4775 Activating RTCP PORT 15561 2013-12-02 15:11:50.498554 [DEBUG] switch_rtp.c:3378 RTCP send rate is: 10000 and packet rate is: 20000 Remote Port: 15561 2013-12-02 15:11:50.498554 [DEBUG] switch_rtp.c:1907 Setting RTCP remote addr to xx.xx.xx.xx:15561 2013-12-02 15:11:50.498554 [INFO] switch_core_media.c:4783 Skipping RTCP ICE (Same as RTP) 2013-12-02 15:11:50.498554 [INFO] switch_rtp.c:2634 Activate RTP/RTCP audio DTLS server 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:4907 Set 2833 dtmf send payload to 101 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:4913 Set 2833 dtmf receive payload to 101 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:4941 Set comfort noise payload to 13 2013-12-02 15:11:50.498554 [INFO] switch_rtp.c:2868 Activating Audio Secure RTP SEND 2013-12-02 15:11:50.498554 [INFO] switch_rtp.c:2846 Activating Audio Secure RTP RECV 2013-12-02 15:11:50.498554 [DEBUG] switch_core_sqldb.c:2357 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80 2013-12-02 15:11:50.498554 [DEBUG] switch_core_sqldb.c:2357 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80 2013-12-02 15:11:50.498554 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/sip:111999@xx.xx.xx.xx:48336! 2013-12-02 15:11:50.498554 [DEBUG] switch_channel.c:3400 Send signal sofia/internal/111998@xx.xx.xx.xx [BREAK] 2013-12-02 15:11:50.498554 [DEBUG] switch_channel.c:3404 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) Callstate Change DOWN -> EARLY 2013-12-02 15:11:50.498554 [WARNING] switch_channel.c:3338 rtp_secure_media invalid in this context. 2013-12-02 15:11:50.498554 [INFO] switch_ivr_originate.c:3482 Sending early media 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [opus:111:48000:60:0]/[G722:9:8000:20:64000] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [opus:111:48000:60:0]/[GSM:3:8000:20:13200] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [opus:111:48000:60:0]/[PCMU:0:8000:20:64000] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [opus:111:48000:60:0]/[PCMA:8:8000:20:64000] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [ISAC:103:16000:30:32000]/[G722:9:8000:20:64000] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [ISAC:103:16000:30:32000]/[GSM:3:8000:20:13200] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [ISAC:103:16000:30:32000]/[PCMU:0:8000:20:64000] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [ISAC:103:16000:30:32000]/[PCMA:8:8000:20:64000] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [ISAC:104:32000:30:32000]/[G722:9:8000:20:64000] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [ISAC:104:32000:30:32000]/[GSM:3:8000:20:13200] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [ISAC:104:32000:30:32000]/[PCMU:0:8000:20:64000] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [ISAC:104:32000:30:32000]/[PCMA:8:8000:20:64000] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [PCMU:0:8000:60:64000]/[G722:9:8000:20:64000] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [PCMU:0:8000:60:64000]/[GSM:3:8000:20:13200] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [PCMU:0:8000:60:64000]/[PCMU:0:8000:20:64000] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3213 Audio Codec Compare [PCMU:0:8000:20:64000] ++++ is saved as a match 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [PCMU:0:8000:60:64000]/[PCMA:8:8000:20:64000] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [PCMA:8:8000:60:64000]/[G722:9:8000:20:64000] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [PCMA:8:8000:60:64000]/[GSM:3:8000:20:13200] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [PCMA:8:8000:60:64000]/[PCMU:0:8000:20:64000] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [PCMA:8:8000:60:64000]/[PCMA:8:8000:20:64000] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3213 Audio Codec Compare [PCMA:8:8000:20:64000] ++++ is saved as a match 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [CN:105:16000:60:0]/[G722:9:8000:20:64000] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [CN:105:16000:60:0]/[GSM:3:8000:20:13200] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [CN:105:16000:60:0]/[PCMU:0:8000:20:64000] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [CN:105:16000:60:0]/[PCMA:8:8000:20:64000] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [CN:13:8000:60:0]/[G722:9:8000:20:64000] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [CN:13:8000:60:0]/[GSM:3:8000:20:13200] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [CN:13:8000:60:0]/[PCMU:0:8000:20:64000] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3159 Audio Codec Compare [CN:13:8000:60:0]/[PCMA:8:8000:20:64000] 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3085 Set telephone-event payload to 126 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:2123 Set Codec sofia/internal/111998@xx.xx.xx.xx PCMU/8000 20 ms 160 samples 64000 bits 2013-12-02 15:11:50.498554 [DEBUG] switch_core_codec.c:111 sofia/internal/111998@xx.xx.xx.xx Original read codec set to PCMU:0 2013-12-02 15:11:50.498554 [WARNING] switch_core_media.c:2324 NO candidate ACL defined, Defaulting to wan.auto 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:2348 Checking Candidate cid: 1 proto: udp type: host addr: 10.4.5.177:63907 2013-12-02 15:11:50.498554 [NOTICE] switch_core_media.c:2362 Save audio Candidate cid: 1 proto: udp type: host addr: 10.4.5.177:63907 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:2348 Checking Candidate cid: 2 proto: udp type: host addr: 10.4.5.177:63907 2013-12-02 15:11:50.498554 [NOTICE] switch_core_media.c:2362 Save audio Candidate cid: 2 proto: udp type: host addr: 10.4.5.177:63907 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:2348 Checking Candidate cid: 1 proto: udp type: srflx addr: xx.xx.xx.xx:52606 2013-12-02 15:11:50.498554 [NOTICE] switch_core_media.c:2357 Choose audio Candidate cid: 1 proto: udp type: srflx addr: xx.xx.xx.xx:52606 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:2348 Checking Candidate cid: 2 proto: udp type: srflx addr: xx.xx.xx.xx:52606 2013-12-02 15:11:50.498554 [NOTICE] switch_core_media.c:2357 Choose audio Candidate cid: 2 proto: udp type: srflx addr: xx.xx.xx.xx:52606 2013-12-02 15:11:50.498554 [NOTICE] switch_core_media.c:2486 setting remote audio ice addr to xx.xx.xx.xx:52606 based on candidate 2013-12-02 15:11:50.498554 [NOTICE] switch_core_media.c:2506 setting remote rtcp audio addr to xx.xx.xx.xx:52606 based on candidate 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:3391 Set 2833 dtmf send/recv payload to 126 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:4563 AUDIO RTP [sofia/internal/111998@xx.xx.xx.xx] 10.188.136.13 port 24380 -> xx.xx.xx.xx port 52606 codec: 0 ms: 20 2013-12-02 15:11:50.498554 [DEBUG] switch_rtp.c:3047 Starting timer [soft] 160 bytes per 20ms 2013-12-02 15:11:50.498554 [INFO] switch_core_media.c:4732 Activating Audio ICE 2013-12-02 15:11:50.498554 [NOTICE] switch_rtp.c:3474 Activating RTP audio ICE: fNi6w7SNINs91kf1:0S3OyzuzaWuRVSio xx.xx.xx.xx:52606 2013-12-02 15:11:50.498554 [INFO] switch_core_media.c:4775 Activating RTCP PORT 52606 2013-12-02 15:11:50.498554 [DEBUG] switch_rtp.c:3378 RTCP send rate is: 10000 and packet rate is: 20000 Remote Port: 52606 2013-12-02 15:11:50.498554 [DEBUG] switch_rtp.c:1907 Setting RTCP remote addr to xx.xx.xx.xx:52606 2013-12-02 15:11:50.498554 [INFO] switch_core_media.c:4783 Skipping RTCP ICE (Same as RTP) 2013-12-02 15:11:50.498554 [INFO] switch_rtp.c:2634 Activate RTP/RTCP audio DTLS client 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:4907 Set 2833 dtmf send payload to 126 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:4913 Set 2833 dtmf receive payload to 126 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:4941 Set comfort noise payload to 106 2013-12-02 15:11:50.498554 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/111998@xx.xx.xx.xx! 2013-12-02 15:11:50.498554 [DEBUG] switch_channel.c:3404 (sofia/internal/111998@xx.xx.xx.xx) Callstate Change RINGING -> EARLY 2013-12-02 15:11:50.498554 [DEBUG] switch_core_media.c:5921 JAMES WAS HERE : isendrecv . 2013-12-02 15:11:50.498554 [DEBUG] mod_sofia.c:2092 Ring SDP: v=0 o=FreeSWITCH 1385972730 1385972731 IN IP4 xx.xx.xx.xx s=FreeSWITCH c=IN IP4 xx.xx.xx.xx t=0 0 a=sendrecv a=msid-semantic: WMS TD8yxg3hg5iVXt7spI8oXPFPaKB5R9yA m=audio 24380 RTP/SAVPF 0 126 106 a=rtpmap:0 PCMU/8000 a=rtpmap:126 telephone-event/8000 a=rtpmap:106 CN/8000 a=ptime:20 a=fingerprint:sha-256 91:9E:50:FA:2E:A5:8E:02:41:1E:FC:A5:8A:B0:0C:1F:98:1F:1B:49:BB:D6:44:A8:E1:01:EA:82:7C:B6:59:1D a=rtcp-mux a=rtcp:24380 IN IP4 xx.xx.xx.xx a=ssrc:1855925413 cname:CxZZDS7JOgvBzsUP a=ssrc:1855925413 msid:TD8yxg3hg5iVXt7spI8oXPFPaKB5R9yA a0 a=ssrc:1855925413 mslabel:TD8yxg3hg5iVXt7spI8oXPFPaKB5R9yA a=ssrc:1855925413 label:TD8yxg3hg5iVXt7spI8oXPFPaKB5R9yAa0 a=ice-ufrag:0S3OyzuzaWuRVSio a=ice-pwd:f7eJQbiuiEVHWGnN a=candidate:2103413470 1 udp 659136 xx.xx.xx.xx 24380 typ host generation 0 2013-12-02 15:11:50.498554 [DEBUG] switch_core_session.c:894 Send signal sofia/internal/111998@xx.xx.xx.xx [BREAK] 2013-12-02 15:11:50.498554 [DEBUG] switch_ivr_originate.c:3533 Originate Resulted in Success: [sofia/internal/sip:111999@xx.xx.xx.xx:48336] 2013-12-02 15:11:50.518541 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/111998@xx.xx.xx.xx [BREAK] 2013-12-02 15:11:50.518541 [DEBUG] sofia.c:5861 Channel sofia/internal/111998@xx.xx.xx.xx entering state [early][183] 2013-12-02 15:11:50.518541 [DEBUG] switch_ivr_originate.c:3533 Originate Resulted in Success: [sofia/internal/sip:111999@xx.xx.xx.xx:48336] 2013-12-02 15:11:50.518541 [DEBUG] switch_core_session.c:894 Send signal sofia/internal/sip:111999@xx.xx.xx.xx:48336 [BREAK] 2013-12-02 15:11:50.518541 [DEBUG] switch_core_session.c:894 Send signal sofia/internal/111998@xx.xx.xx.xx [BREAK] 2013-12-02 15:11:50.518541 [DEBUG] switch_ivr_bridge.c:1440 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2013-12-02 15:11:50.518541 [DEBUG] switch_core_session.c:1374 Send signal sofia/internal/sip:111999@xx.xx.xx.xx:48336 [BREAK] 2013-12-02 15:11:50.518541 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) Running State Change CS_EXCHANGE_MEDIA 2013-12-02 15:11:50.518541 [DEBUG] switch_core_state_machine.c:532 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) State EXCHANGE_MEDIA 2013-12-02 15:11:50.518541 [DEBUG] mod_sofia.c:592 SOFIA EXCHANGE_MEDIA 2013-12-02 15:11:54.378535 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/sip:111999@xx.xx.xx.xx:48336 [BREAK] 2013-12-02 15:11:54.378535 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/sip:111999@xx.xx.xx.xx:48336 [BREAK] 2013-12-02 15:11:54.398589 [DEBUG] sofia.c:5861 Channel sofia/internal/sip:111999@xx.xx.xx.xx:48336 entering state [completing][200] 2013-12-02 15:11:54.398589 [DEBUG] sofia.c:5868 Duplicate SDP v=0 o=- 751491027366329237 2 IN IP4 127.0.0.1 s=- t=0 0 a=msid-semantic: WMS m=audio 15561 RTP/SAVPF 0 8 13 101 c=IN IP4 xx.xx.xx.xx a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:13 CN/8000 a=rtpmap:101 telephone-event/8000 a=rtcp:1 IN IP4 0.0.0.0 a=candidate:622902765 1 udp 2113937151 xx.xx.xx.xx 41736 typ host generation 0 a=candidate:1805861149 1 tcp 1509957375 xx.xx.xx.xx 49160 typ host generation 0 a=candidate:1739408229 1 udp 1845501695 xx.xx.xx.xx 15561 typ srflx raddr xx.xx.xx.xx rport 41736 generation 0 a=ice-ufrag:mbtnHm5KfkZqEDnI a=ice-pwd:nA2j+Sq8+sF/DnCRucATdnDd a=mid:audio a=rtcp-mux a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:sULSASTq8o0rKq0N+g5LHr4bCcdMFXHsXjQ5ijLK a=candidate:622902765 1 udp 2113937151 xx.xx.xx.xx 41736 typ host generation 0 a=candidate:1805861149 1 tcp 1509957375 xx.xx.xx.xx 49160 typ host generation 0 a=candidate:1739408229 1 udp 1845501695 xx.xx.xx.xx 15561 typ srflx raddr xx.xx.xx.xx rport 41736 generation 0 2013-12-02 15:11:54.398589 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/sip:111999@xx.xx.xx.xx:48336 [BREAK] 2013-12-02 15:11:54.398589 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/sip:111999@xx.xx.xx.xx:48336 [BREAK] 2013-12-02 15:11:54.418547 [DEBUG] sofia.c:5861 Channel sofia/internal/sip:111999@xx.xx.xx.xx:48336 entering state [ready][200] 2013-12-02 15:11:54.418547 [DEBUG] switch_channel.c:3639 Send signal sofia/internal/111998@xx.xx.xx.xx [BREAK] 2013-12-02 15:11:54.418547 [NOTICE] sofia.c:6586 Channel [sofia/internal/sip:111999@xx.xx.xx.xx:48336] has been answered 2013-12-02 15:11:54.418547 [DEBUG] switch_channel.c:3685 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) Callstate Change EARLY -> ACTIVE 2013-12-02 15:11:54.418547 [DEBUG] switch_core_media.c:5921 JAMES WAS HERE : isendrecv . 2013-12-02 15:11:54.418547 [DEBUG] mod_sofia.c:775 Local SDP sofia/internal/111998@xx.xx.xx.xx: v=0 o=FreeSWITCH 1385972730 1385972732 IN IP4 xx.xx.xx.xx s=FreeSWITCH c=IN IP4 xx.xx.xx.xx t=0 0 a=sendrecv a=msid-semantic: WMS TD8yxg3hg5iVXt7spI8oXPFPaKB5R9yA m=audio 24380 RTP/SAVPF 0 126 106 a=rtpmap:0 PCMU/8000 a=rtpmap:126 telephone-event/8000 a=rtpmap:106 CN/8000 a=ptime:20 a=fingerprint:sha-256 91:9E:50:FA:2E:A5:8E:02:41:1E:FC:A5:8A:B0:0C:1F:98:1F:1B:49:BB:D6:44:A8:E1:01:EA:82:7C:B6:59:1D a=rtcp-mux a=rtcp:24380 IN IP4 xx.xx.xx.xx a=ssrc:1855925413 cname:CxZZDS7JOgvBzsUP a=ssrc:1855925413 msid:TD8yxg3hg5iVXt7spI8oXPFPaKB5R9yA a0 a=ssrc:1855925413 mslabel:TD8yxg3hg5iVXt7spI8oXPFPaKB5R9yA a=ssrc:1855925413 label:TD8yxg3hg5iVXt7spI8oXPFPaKB5R9yAa0 a=ice-ufrag:0S3OyzuzaWuRVSio a=ice-pwd:f7eJQbiuiEVHWGnN a=candidate:2702679747 1 udp 659136 xx.xx.xx.xx 24380 typ host generation 0 2013-12-02 15:11:54.418547 [DEBUG] switch_core_session.c:894 Send signal sofia/internal/111998@xx.xx.xx.xx [BREAK] 2013-12-02 15:11:54.418547 [NOTICE] switch_ivr_bridge.c:484 Channel [sofia/internal/111998@xx.xx.xx.xx] has been answered 2013-12-02 15:11:54.418547 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/111998@xx.xx.xx.xx [BREAK] 2013-12-02 15:11:54.418547 [DEBUG] switch_channel.c:3685 (sofia/internal/111998@xx.xx.xx.xx) Callstate Change EARLY -> ACTIVE 2013-12-02 15:11:54.418547 [DEBUG] sofia.c:5861 Channel sofia/internal/111998@xx.xx.xx.xx entering state [completed][200] 2013-12-02 15:11:54.698537 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/111998@xx.xx.xx.xx [BREAK] 2013-12-02 15:11:54.698537 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/111998@xx.xx.xx.xx [BREAK] 2013-12-02 15:11:54.698537 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/111998@xx.xx.xx.xx [BREAK] 2013-12-02 15:11:54.698537 [DEBUG] sofia.c:5861 Channel sofia/internal/111998@xx.xx.xx.xx entering state [ready][200] 2013-12-02 15:11:54.698537 [DEBUG] switch_core_session.c:956 Send signal sofia/internal/sip:111999@xx.xx.xx.xx:48336 [BREAK] 2013-12-02 15:11:54.698537 [DEBUG] switch_core_session.c:956 Send signal sofia/internal/111998@xx.xx.xx.xx [BREAK] 2013-12-02 15:11:58.198537 [INFO] switch_rtp.c:2449 Changing audio DTLS state from HANDSHAKE to SETUP 2013-12-02 15:11:58.198537 [INFO] switch_rtp.c:2368 audio Fingerprint Verified. 2013-12-02 15:11:58.198537 [INFO] switch_rtp.c:2868 Activating Audio Secure RTP SEND 2013-12-02 15:11:58.198537 [INFO] switch_rtp.c:2846 Activating Audio Secure RTP RECV 2013-12-02 15:11:58.198537 [INFO] switch_rtp.c:2408 Changing audio DTLS state from SETUP to READY 2013-12-02 15:11:58.198537 [DEBUG] switch_core_sqldb.c:2357 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80 2013-12-02 15:11:58.198537 [DEBUG] switch_core_sqldb.c:2357 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80 2013-12-02 15:12:33.938558 [ERR] switch_rtp.c:718 No audio stun for a long time! 2013-12-02 15:13:04.218537 [ERR] switch_rtp.c:718 No audio stun for a long time! 2013-12-02 15:13:23.978537 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/111998@xx.xx.xx.xx [BREAK] 2013-12-02 15:13:23.978537 [NOTICE] sofia.c:715 Hangup sofia/internal/111998@xx.xx.xx.xx [CS_EXECUTE] [NORMAL_CLEARING] 2013-12-02 15:13:23.978537 [DEBUG] switch_channel.c:3211 Send signal sofia/internal/111998@xx.xx.xx.xx [KILL] 2013-12-02 15:13:23.978537 [DEBUG] switch_core_session.c:1374 Send signal sofia/internal/111998@xx.xx.xx.xx [BREAK] 2013-12-02 15:13:23.978537 [DEBUG] switch_ivr_bridge.c:647 BRIDGE THREAD DONE [sofia/internal/111998@xx.xx.xx.xx] 2013-12-02 15:13:23.978537 [DEBUG] switch_ivr_bridge.c:672 Send signal sofia/internal/sip:111999@xx.xx.xx.xx:48336 [BREAK] 2013-12-02 15:13:23.998540 [DEBUG] switch_ivr_bridge.c:647 BRIDGE THREAD DONE [sofia/internal/sip:111999@xx.xx.xx.xx:48336] 2013-12-02 15:13:23.998540 [DEBUG] switch_ivr_bridge.c:672 Send signal sofia/internal/111998@xx.xx.xx.xx [BREAK] 2013-12-02 15:13:23.998540 [NOTICE] switch_ivr_bridge.c:735 Hangup sofia/internal/sip:111999@xx.xx.xx.xx:48336 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] 2013-12-02 15:13:23.998540 [DEBUG] switch_channel.c:3211 Send signal sofia/internal/sip:111999@xx.xx.xx.xx:48336 [KILL] 2013-12-02 15:13:23.998540 [DEBUG] switch_core_session.c:1374 Send signal sofia/internal/sip:111999@xx.xx.xx.xx:48336 [BREAK] 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:532 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) State EXCHANGE_MEDIA going to sleep 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) Running State Change CS_HANGUP 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:730 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) State HANGUP 2013-12-02 15:13:23.998540 [DEBUG] mod_sofia.c:407 sofia/internal/sip:111999@xx.xx.xx.xx:48336 Overriding SIP cause 480 with 200 from the other leg 2013-12-02 15:13:23.998540 [DEBUG] mod_sofia.c:413 Channel sofia/internal/sip:111999@xx.xx.xx.xx:48336 hanging up, cause: NORMAL_CLEARING 2013-12-02 15:13:23.998540 [DEBUG] mod_sofia.c:465 Sending BYE to sofia/internal/sip:111999@xx.xx.xx.xx:48336 2013-12-02 15:13:23.998540 [DEBUG] switch_ivr_bridge.c:1538 sofia/internal/sip:111999@xx.xx.xx.xx:48336 skip receive message [UNBRIDGE] (channel is hungup already) 2013-12-02 15:13:23.998540 [DEBUG] switch_ivr_bridge.c:1541 sofia/internal/111998@xx.xx.xx.xx skip receive message [UNBRIDGE] (channel is hungup already) 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:58 sofia/internal/sip:111999@xx.xx.xx.xx:48336 Standard HANGUP, cause: NORMAL_CLEARING 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:730 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) State HANGUP going to sleep 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:743 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) Callstate Change ACTIVE -> HANGUP 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:498 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) State Change CS_HANGUP -> CS_REPORTING 2013-12-02 15:13:23.998540 [DEBUG] switch_core_session.c:1374 Send signal sofia/internal/sip:111999@xx.xx.xx.xx:48336 [BREAK] 2013-12-02 15:13:23.998540 [DEBUG] switch_core_session.c:2843 sofia/internal/111998@xx.xx.xx.xx skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:529 (sofia/internal/111998@xx.xx.xx.xx) State EXECUTE going to sleep 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/111998@xx.xx.xx.xx) Running State Change CS_HANGUP 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) Running State Change CS_REPORTING 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:815 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) State REPORTING 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:102 sofia/internal/sip:111999@xx.xx.xx.xx:48336 Standard REPORTING, cause: NORMAL_CLEARING 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:815 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) State REPORTING going to sleep 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:730 (sofia/internal/111998@xx.xx.xx.xx) State HANGUP 2013-12-02 15:13:23.998540 [DEBUG] mod_sofia.c:413 Channel sofia/internal/111998@xx.xx.xx.xx hanging up, cause: NORMAL_CLEARING 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:492 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) State Change CS_REPORTING -> CS_DESTROY 2013-12-02 15:13:23.998540 [DEBUG] switch_core_session.c:1374 Send signal sofia/internal/sip:111999@xx.xx.xx.xx:48336 [BREAK] 2013-12-02 15:13:23.998540 [DEBUG] switch_core_session.c:1582 Session 47 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) Locked, Waiting on external entities 2013-12-02 15:13:23.998540 [NOTICE] switch_core_session.c:1600 Session 47 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) Ended 2013-12-02 15:13:23.998540 [NOTICE] switch_core_session.c:1604 Close Channel sofia/internal/sip:111999@xx.xx.xx.xx:48336 [CS_DESTROY] 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:617 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) Callstate Change HANGUP -> DOWN 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) Running State Change CS_DESTROY 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:58 sofia/internal/111998@xx.xx.xx.xx Standard HANGUP, cause: NORMAL_CLEARING 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:730 (sofia/internal/111998@xx.xx.xx.xx) State HANGUP going to sleep 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:630 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) State DESTROY 2013-12-02 15:13:23.998540 [DEBUG] mod_sofia.c:323 sofia/internal/sip:111999@xx.xx.xx.xx:48336 SOFIA DESTROY 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:743 (sofia/internal/111998@xx.xx.xx.xx) Callstate Change ACTIVE -> HANGUP 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:109 sofia/internal/sip:111999@xx.xx.xx.xx:48336 Standard DESTROY 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:630 (sofia/internal/sip:111999@xx.xx.xx.xx:48336) State DESTROY going to sleep 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:498 (sofia/internal/111998@xx.xx.xx.xx) State Change CS_HANGUP -> CS_REPORTING 2013-12-02 15:13:23.998540 [DEBUG] switch_core_session.c:1374 Send signal sofia/internal/111998@xx.xx.xx.xx [BREAK] 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/111998@xx.xx.xx.xx) Running State Change CS_REPORTING 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:815 (sofia/internal/111998@xx.xx.xx.xx) State REPORTING 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:102 sofia/internal/111998@xx.xx.xx.xx Standard REPORTING, cause: NORMAL_CLEARING 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:815 (sofia/internal/111998@xx.xx.xx.xx) State REPORTING going to sleep 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:492 (sofia/internal/111998@xx.xx.xx.xx) State Change CS_REPORTING -> CS_DESTROY 2013-12-02 15:13:23.998540 [DEBUG] switch_core_session.c:1374 Send signal sofia/internal/111998@xx.xx.xx.xx [BREAK] 2013-12-02 15:13:23.998540 [DEBUG] switch_core_session.c:1582 Session 46 (sofia/internal/111998@xx.xx.xx.xx) Locked, Waiting on external entities 2013-12-02 15:13:23.998540 [NOTICE] switch_core_session.c:1600 Session 46 (sofia/internal/111998@xx.xx.xx.xx) Ended 2013-12-02 15:13:23.998540 [NOTICE] switch_core_session.c:1604 Close Channel sofia/internal/111998@xx.xx.xx.xx [CS_DESTROY] 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:617 (sofia/internal/111998@xx.xx.xx.xx) Callstate Change HANGUP -> DOWN 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/111998@xx.xx.xx.xx) Running State Change CS_DESTROY 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:630 (sofia/internal/111998@xx.xx.xx.xx) State DESTROY 2013-12-02 15:13:23.998540 [DEBUG] mod_sofia.c:323 sofia/internal/111998@xx.xx.xx.xx SOFIA DESTROY 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:109 sofia/internal/111998@xx.xx.xx.xx Standard DESTROY 2013-12-02 15:13:23.998540 [DEBUG] switch_core_state_machine.c:630 (sofia/internal/111998@xx.xx.xx.xx) State DESTROY going to sleep -- View this message in context: http://freeswitch-users.2379917.n2.nabble.com/No-audio-in-inbound-call-for-a... Sent from the freeswitch-users mailing list archive at Nabble.com.