******************************************************** FREESWITCH2 - calls are not sent to the registered user ******************************************************** recv 1038 bytes from udp/[10.0.0.146]:5060 at 16:02:09.615698: ------------------------------------------------------------------------ INVITE sip:2200@10.0.0.145 SIP/2.0 From: london.devserver.sytelco.com ;tag=ACU-1370-d75b057b To: 2200 Contact: Call-ID: 0044B001-0000C3E5-59400C81-00000009@10.0.0.146 CSeq: 28024 INVITE Content-Length: 237 Content-Type: application/sdp Allow: INVITE Allow: ACK Allow: BYE Allow: CANCEL Allow: OPTIONS Allow: NOTIFY Allow: REFER Allow: PRACK Allow: INFO Allow: UPDATE Allow: MESSAGE Accept: application/sdp Accept: application/isup Accept: application/qsig Accept: multipart/mixed Accept-Encoding: identity Accept-Language: en Supported: replaces Supported: 100rel Via: SIP/2.0/UDP 10.0.0.146:5060;branch=z9hG4bKa7d0f6d5-5051-11e7-854a-c8c2c2f34e3c;rport Max-Forwards: 70 v=0 o=aculab-0044B001 25386 25386 IN IP4 10.0.0.146 s=- c=IN IP4 10.0.0.146 t=0 0 m=audio 30790 RTP/AVP 8 18 96 a=rtpmap:8 PCMA/8000 a=ptime:20 a=rtpmap:18 G729/8000 a=ptime:30 a=rtpmap:96 telephone-event/8000 a=fmtp:96 0-15 ------------------------------------------------------------------------ send 444 bytes to udp/[10.0.0.146]:5060 at 16:02:09.615698: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.0.0.146:5060;branch=z9hG4bKa7d0f6d5-5051-11e7-854a-c8c2c2f34e3c;rport=5060 From: london.devserver.sytelco.com ;tag=ACU-1370-d75b057b To: 2200 Call-ID: 0044B001-0000C3E5-59400C81-00000009@10.0.0.146 CSeq: 28024 INVITE User-Agent: FreeSWITCH-mod_sofia/1.6.17+git~20170417T142108Z~0fc0946461~64bit Content-Length: 0 ------------------------------------------------------------------------ 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com [1424da2f-2c00-4eef-a4c5-bfc6f7785de0] 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) Running State Change CS_NEW (Cur 1 Tot 35) 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] sofia.c:9834 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com receiving invite from 10.0.0.146:5060 version: 1.6.17 git 0fc0946 2017-04-17 14:21:08Z 64bit 2017-06-13 17:02:09.616638 [DEBUG] sofia.c:9950 IP 10.0.0.146 Approved by acl "domains[]". Access Granted. 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] sofia.c:7048 Channel sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com entering state [received][100] 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] sofia.c:7058 Remote SDP: 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 v=0 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 o=aculab-0044B001 25386 25386 IN IP4 10.0.0.146 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 s=- 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 c=IN IP4 10.0.0.146 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 t=0 0 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 m=audio 30790 RTP/AVP 8 18 96 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 a=rtpmap:8 PCMA/8000 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 a=rtpmap:18 G729/8000 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 a=rtpmap:96 telephone-event/8000 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 a=fmtp:96 0-15 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 a=ptime:20 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 a=ptime:30 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] sofia.c:7450 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) State Change CS_NEW -> CS_INIT 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) State NEW 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) Running State Change CS_INIT (Cur 1 Tot 35) 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) State INIT 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] mod_sofia.c:90 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com SOFIA INIT 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] switch_core_state_machine.c:40 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Standard INIT 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) State Change CS_INIT -> CS_ROUTING 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) State INIT going to sleep 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) Running State Change CS_ROUTING (Cur 1 Tot 35) 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] switch_channel.c:2249 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) Callstate Change DOWN -> RINGING 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) State ROUTING 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] mod_sofia.c:143 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com SOFIA ROUTING 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] switch_core_state_machine.c:236 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Standard ROUTING 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [INFO] mod_dialplan_xml.c:637 Processing london.devserver.sytelco.com ->2200 in context public 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com parsing [public->unloop] continue=false 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com parsing [public->outside_call] continue=true 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Absolute Condition [outside_call] 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Action set(outside_call=true) 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com parsing [public->call_debug] continue=true 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com parsing [public->extensions_nailup] continue=false 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Regex (PASS) [extensions_nailup] network_addr(10.0.0.146) =~ /10.0.0.146/ break=on-false 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Regex (PASS) [extensions_nailup] destination_number(2200) =~ /^(\d{4})$/ break=on-false 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Action export(dialed_extension=2200) 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Action set(call_timeout=30) 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Action bridge(user/${dialed_extension}@${caller_id_name}) 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Action hangup() 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) State Change CS_ROUTING -> CS_EXECUTE 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) State ROUTING going to sleep 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) Running State Change CS_EXECUTE (Cur 1 Tot 35) 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) State EXECUTE 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] mod_sofia.c:198 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com SOFIA EXECUTE 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] switch_core_state_machine.c:328 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Standard EXECUTE 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 EXECUTE sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com set(outside_call=true) 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] mod_dptools.c:1530 SET sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com [outside_call]=[true] 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 EXECUTE sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com export(RFC2822_DATE=Tue, 13 Jun 2017 17:02:09 +0100) 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Tue, 13 Jun 2017 17:02:09 +0100] 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 EXECUTE sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com export(dialed_extension=2200) 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dialed_extension]=[2200] 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 EXECUTE sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com set(call_timeout=30) 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] mod_dptools.c:1530 SET sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com [call_timeout]=[30] 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 EXECUTE sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com bridge(user/2200@london.devserver.sytelco.com) 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] switch_channel.c:1250 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com EXPORTING[export_vars] [RFC2822_DATE]=[Tue, 13 Jun 2017 17:02:09 +0100] to event 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] switch_channel.c:1250 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com EXPORTING[export_vars] [dialed_extension]=[2200] to event 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.616638 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables 2017-06-13 17:02:09.706637 [CONSOLE] mod_xml_curl.c:323 XML response is in C:/Windows/TEMP/bfdc098e-002b-471a-a893-2282c172f22d.tmp.xml 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.706637 [DEBUG] switch_channel.c:1250 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com EXPORTING[export_vars] [RFC2822_DATE]=[Tue, 13 Jun 2017 17:02:09 +0100] to event 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.706637 [DEBUG] switch_channel.c:1250 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com EXPORTING[export_vars] [dialed_extension]=[2200] to event 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:09.706637 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:09.706637 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/2200@df7jal23ls0d.invalid [76552e5e-be86-445e-82e7-baafc543c76d] 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:09.706637 [DEBUG] mod_sofia.c:4818 (sofia/internal/2200@df7jal23ls0d.invalid) State Change CS_NEW -> CS_INIT 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:09.726640 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/2200@df7jal23ls0d.invalid) Running State Change CS_INIT (Cur 2 Tot 36) 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:09.726640 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/2200@df7jal23ls0d.invalid) State INIT 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:09.726640 [DEBUG] mod_sofia.c:90 sofia/internal/2200@df7jal23ls0d.invalid SOFIA INIT 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:09.726640 [DEBUG] sofia_glue.c:1264 sips:2200@10.1.0.41:58790;rtcweb-breaker=no;transport=wss Setting proxy route to sofia/internal/2200@df7jal23ls0d.invalid 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:09.726640 [DEBUG] sofia_glue.c:1295 sofia/internal/2200@df7jal23ls0d.invalid sending invite version: 1.6.17 git 0fc0946 2017-04-17 14:21:08Z 64bit 76552e5e-be86-445e-82e7-baafc543c76d Local SDP: 76552e5e-be86-445e-82e7-baafc543c76d v=0 76552e5e-be86-445e-82e7-baafc543c76d o=FreeSWITCH 1497345553 1497345554 IN IP4 10.0.0.145 76552e5e-be86-445e-82e7-baafc543c76d s=FreeSWITCH 76552e5e-be86-445e-82e7-baafc543c76d c=IN IP4 10.0.0.145 76552e5e-be86-445e-82e7-baafc543c76d t=0 0 76552e5e-be86-445e-82e7-baafc543c76d a=msid-semantic: WMS LCZEb2kW6BGxMQ9H9n0JARxq4poeyZ9H 76552e5e-be86-445e-82e7-baafc543c76d m=audio 24176 RTP/SAVPF 8 101 76552e5e-be86-445e-82e7-baafc543c76d a=rtpmap:8 PCMA/8000 76552e5e-be86-445e-82e7-baafc543c76d a=rtpmap:101 telephone-event/8000 76552e5e-be86-445e-82e7-baafc543c76d a=fingerprint:sha-256 D9:2E:2E:8B:CA:AE:77:2D:DC:B1:81:66:A6:16:16:70:64:92:E3:5F:30:DA:90:68:22:88:D8:78:50:30:9C:9A 76552e5e-be86-445e-82e7-baafc543c76d a=setup:actpass 76552e5e-be86-445e-82e7-baafc543c76d a=rtcp-mux 76552e5e-be86-445e-82e7-baafc543c76d a=rtcp:24176 IN IP4 10.0.0.145 76552e5e-be86-445e-82e7-baafc543c76d a=ssrc:733119777 cname:ayoj9r3Cp2nsbNai 76552e5e-be86-445e-82e7-baafc543c76d a=ssrc:733119777 msid:LCZEb2kW6BGxMQ9H9n0JARxq4poeyZ9H a0 76552e5e-be86-445e-82e7-baafc543c76d a=ssrc:733119777 mslabel:LCZEb2kW6BGxMQ9H9n0JARxq4poeyZ9H 76552e5e-be86-445e-82e7-baafc543c76d a=ssrc:733119777 label:LCZEb2kW6BGxMQ9H9n0JARxq4poeyZ9Ha0 76552e5e-be86-445e-82e7-baafc543c76d a=ice-ufrag:PPMxsmnCfT15WBc4 76552e5e-be86-445e-82e7-baafc543c76d a=ice-pwd:SM4FAIgCr8ysHd7WSwAO9QWu 76552e5e-be86-445e-82e7-baafc543c76d a=candidate:0246028599 1 udp 659136 10.0.0.145 24176 typ host generation 0 76552e5e-be86-445e-82e7-baafc543c76d a=candidate:0246028599 2 udp 659136 10.0.0.145 24176 typ host generation 0 76552e5e-be86-445e-82e7-baafc543c76d a=ptime:20 76552e5e-be86-445e-82e7-baafc543c76d a=sendrecv 76552e5e-be86-445e-82e7-baafc543c76d 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:09.726640 [DEBUG] switch_core_state_machine.c:40 sofia/internal/2200@df7jal23ls0d.invalid Standard INIT 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:09.726640 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/2200@df7jal23ls0d.invalid) State Change CS_INIT -> CS_ROUTING 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:09.726640 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/2200@df7jal23ls0d.invalid) State INIT going to sleep 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:09.726640 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/2200@df7jal23ls0d.invalid) Running State Change CS_ROUTING (Cur 2 Tot 36) 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:09.726640 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/2200@df7jal23ls0d.invalid) State ROUTING 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:09.726640 [DEBUG] mod_sofia.c:143 sofia/internal/2200@df7jal23ls0d.invalid SOFIA ROUTING 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:09.726640 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/2200@df7jal23ls0d.invalid) State Change CS_ROUTING -> CS_CONSUME_MEDIA 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:09.726640 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/2200@df7jal23ls0d.invalid) State ROUTING going to sleep 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:09.726640 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/2200@df7jal23ls0d.invalid) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 36) 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:09.726640 [DEBUG] sofia.c:7048 Channel sofia/internal/2200@df7jal23ls0d.invalid entering state [calling][0] 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:09.726640 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/2200@df7jal23ls0d.invalid) State CONSUME_MEDIA 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:09.726640 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/2200@df7jal23ls0d.invalid) State CONSUME_MEDIA going to sleep 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:39.006713 [NOTICE] switch_ivr_originate.c:3605 Hangup sofia/internal/2200@df7jal23ls0d.invalid [CS_CONSUME_MEDIA] [NO_ANSWER] 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:39.006713 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/2200@df7jal23ls0d.invalid) Running State Change CS_HANGUP (Cur 2 Tot 36) 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:39.006713 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/2200@df7jal23ls0d.invalid) Callstate Change DOWN -> HANGUP 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:39.006713 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/2200@df7jal23ls0d.invalid) State HANGUP 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:39.006713 [DEBUG] mod_sofia.c:438 Channel sofia/internal/2200@df7jal23ls0d.invalid hanging up, cause: NO_ANSWER 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:39.006713 [NOTICE] switch_ivr_originate.c:2845 Cannot create outgoing channel of type [user] cause: [NO_ANSWER] 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:39.006713 [DEBUG] switch_ivr_originate.c:3833 Originate Resulted in Error Cause: 19 [NO_ANSWER] 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:39.006713 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/internal/2200@df7jal23ls0d.invalid 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:39.006713 [DEBUG] switch_core_state_machine.c:60 sofia/internal/2200@df7jal23ls0d.invalid Standard HANGUP, cause: NO_ANSWER 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:39.006713 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/2200@df7jal23ls0d.invalid) State HANGUP going to sleep 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:39.006713 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/2200@df7jal23ls0d.invalid) State Change CS_HANGUP -> CS_REPORTING 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:39.006713 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/2200@df7jal23ls0d.invalid) Running State Change CS_REPORTING (Cur 2 Tot 36) 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:39.006713 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/2200@df7jal23ls0d.invalid) State REPORTING 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:39.006713 [DEBUG] switch_core_state_machine.c:174 sofia/internal/2200@df7jal23ls0d.invalid Standard REPORTING, cause: NO_ANSWER 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:39.006713 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/2200@df7jal23ls0d.invalid) State REPORTING going to sleep 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:39.006713 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/2200@df7jal23ls0d.invalid) State Change CS_REPORTING -> CS_DESTROY 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:39.006713 [DEBUG] switch_core_session.c:1664 Session 36 (sofia/internal/2200@df7jal23ls0d.invalid) Locked, Waiting on external entities 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:39.006713 [NOTICE] switch_core_session.c:1682 Session 36 (sofia/internal/2200@df7jal23ls0d.invalid) Ended 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:39.006713 [NOTICE] switch_core_session.c:1686 Close Channel sofia/internal/2200@df7jal23ls0d.invalid [CS_DESTROY] 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:39.006713 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/2200@df7jal23ls0d.invalid) Running State Change CS_DESTROY (Cur 1 Tot 36) 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:39.006713 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/2200@df7jal23ls0d.invalid) State DESTROY 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:39.006713 [DEBUG] mod_sofia.c:343 sofia/internal/2200@df7jal23ls0d.invalid SOFIA DESTROY 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:39.006713 [DEBUG] switch_core_state_machine.c:181 sofia/internal/2200@df7jal23ls0d.invalid Standard DESTROY 76552e5e-be86-445e-82e7-baafc543c76d 2017-06-13 17:02:39.006713 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/2200@df7jal23ls0d.invalid) State DESTROY going to sleep 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:39.006713 [INFO] mod_dptools.c:3418 Originate Failed. Cause: NO_ANSWER 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 EXECUTE sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com hangup() 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:39.016637 [NOTICE] mod_dptools.c:1286 Hangup sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com [CS_EXECUTE] [NORMAL_CLEARING] 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:39.016637 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) Callstate Change RINGING -> HANGUP 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:39.016637 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) State HANGUP 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:39.016637 [DEBUG] mod_sofia.c:438 Channel sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com hanging up, cause: NORMAL_CLEARING 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:39.016637 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 480 send 967 bytes to udp/[10.0.0.146]:5060 at 16:02:39.023638: ------------------------------------------------------------------------ SIP/2.0 480 Temporarily Unavailable Via: SIP/2.0/UDP 10.0.0.146:5060;branch=z9hG4bKa7d0f6d5-5051-11e7-854a-c8c2c2f34e3c;rport=5060 Max-Forwards: 70 From: london.devserver.sytelco.com ;tag=ACU-1370-d75b057b To: 2200 ;tag=3cZyv237Sream Call-ID: 0044B001-0000C3E5-59400C81-00000009@10.0.0.146 CSeq: 28024 INVITE User-Agent: FreeSWITCH-mod_sofia/1.6.17+git~20170417T142108Z~0fc0946461~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Reason: Q.850;cause=16;text="NORMAL_CLEARING" Content-Length: 0 Remote-Party-ID: "2200" ;party=calling;privacy=off;screen=no ------------------------------------------------------------------------ 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:39.016637 [DEBUG] switch_core_state_machine.c:60 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Standard HANGUP, cause: NORMAL_CLEARING 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:39.016637 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) State HANGUP going to sleep 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:39.016637 [DEBUG] switch_core_session.c:2814 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:39.016637 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) State EXECUTE going to sleep 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:39.016637 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) Running State Change CS_HANGUP (Cur 1 Tot 36) 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:39.016637 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) State Change CS_HANGUP -> CS_REPORTING 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:39.016637 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) Running State Change CS_REPORTING (Cur 1 Tot 36) recv 406 bytes from udp/[10.0.0.146]:5060 at 16:02:39.025638: ------------------------------------------------------------------------ ACK sip:2200@10.0.0.145 SIP/2.0 From: london.devserver.sytelco.com ;tag=ACU-1370-d75b057b To: 2200 ;tag=3cZyv237Sream Call-ID: 0044B001-0000C3E5-59400C81-00000009@10.0.0.146 CSeq: 28024 ACK Content-Length: 0 Via: SIP/2.0/UDP 10.0.0.146:5060;branch=z9hG4bKa7d0f6d5-5051-11e7-854a-c8c2c2f34e3c;rport Max-Forwards: 70 ------------------------------------------------------------------------ 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:39.016637 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) State REPORTING 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:39.016637 [DEBUG] switch_core_state_machine.c:174 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Standard REPORTING, cause: NORMAL_CLEARING 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:39.016637 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) State REPORTING going to sleep 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:39.016637 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) State Change CS_REPORTING -> CS_DESTROY 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:39.016637 [DEBUG] switch_core_session.c:1664 Session 35 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) Locked, Waiting on external entities 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:39.016637 [NOTICE] switch_core_session.c:1682 Session 35 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) Ended 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:39.016637 [NOTICE] switch_core_session.c:1686 Close Channel sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com [CS_DESTROY] 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:39.016637 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) Running State Change CS_DESTROY (Cur 0 Tot 36) 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:39.016637 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) State DESTROY 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:39.016637 [DEBUG] mod_sofia.c:343 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com SOFIA DESTROY 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:39.026637 [DEBUG] switch_core_state_machine.c:181 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Standard DESTROY 1424da2f-2c00-4eef-a4c5-bfc6f7785de0 2017-06-13 17:02:39.026637 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) State DESTROY going to sleep ********************************************************** FREESWITCH1 - calls are presented to the registered users ********************************************************** recv 1035 bytes from udp/[10.0.0.146]:5060 at 16:06:47.991677: ------------------------------------------------------------------------ INVITE sip:2200@10.0.0.34 SIP/2.0 From: london.devserver.sytelco.com ;tag=ACU-18be-e7f2ccd2 To: 2200 Contact: Call-ID: 00447001-0000C3F8-59400D97-00000001@10.0.0.146 CSeq: 26500 INVITE Content-Length: 236 Content-Type: application/sdp Allow: INVITE Allow: ACK Allow: BYE Allow: CANCEL Allow: OPTIONS Allow: NOTIFY Allow: REFER Allow: PRACK Allow: INFO Allow: UPDATE Allow: MESSAGE Accept: application/sdp Accept: application/isup Accept: application/qsig Accept: multipart/mixed Accept-Encoding: identity Accept-Language: en Supported: replaces Supported: 100rel Via: SIP/2.0/UDP 10.0.0.146:5060;branch=z9hG4bK4dbee997-5052-11e7-97ac-9a138dd73e1d;rport Max-Forwards: 70 v=0 o=aculab-00447001 18467 18467 IN IP4 10.0.0.146 s=- c=IN IP4 10.0.0.146 t=0 0 m=audio 9022 RTP/AVP 8 18 96 a=rtpmap:8 PCMA/8000 a=ptime:20 a=rtpmap:18 G729/8000 a=ptime:30 a=rtpmap:96 telephone-event/8000 a=fmtp:96 0-15 ------------------------------------------------------------------------ send 443 bytes to udp/[10.0.0.146]:5060 at 16:06:47.992669: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.0.0.146:5060;branch=z9hG4bK4dbee997-5052-11e7-97ac-9a138dd73e1d;rport=5060 From: london.devserver.sytelco.com ;tag=ACU-18be-e7f2ccd2 To: 2200 Call-ID: 00447001-0000C3F8-59400D97-00000001@10.0.0.146 CSeq: 26500 INVITE User-Agent: FreeSWITCH-mod_sofia/1.6.17+git~20170417T142108Z~0fc0946461~64bit Content-Length: 0 ------------------------------------------------------------------------ 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:47.992669 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com [8d3a228a-1026-458b-9305-252733d0b5ad] 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:47.992669 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) Running State Change CS_NEW (Cur 1 Tot 33) 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:47.992669 [DEBUG] sofia.c:9834 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com receiving invite from 10.0.0.146:5060 version: 1.6.17 git 0fc0946 2017-04-17 14:21:08Z 64bit 2017-06-13 17:06:47.992669 [DEBUG] sofia.c:9950 IP 10.0.0.146 Approved by acl "domains[]". Access Granted. 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:47.992669 [DEBUG] sofia.c:7048 Channel sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com entering state [received][100] 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:47.992669 [DEBUG] sofia.c:7058 Remote SDP: 8d3a228a-1026-458b-9305-252733d0b5ad v=0 8d3a228a-1026-458b-9305-252733d0b5ad o=aculab-00447001 18467 18467 IN IP4 10.0.0.146 8d3a228a-1026-458b-9305-252733d0b5ad s=- 8d3a228a-1026-458b-9305-252733d0b5ad c=IN IP4 10.0.0.146 8d3a228a-1026-458b-9305-252733d0b5ad t=0 0 8d3a228a-1026-458b-9305-252733d0b5ad m=audio 9022 RTP/AVP 8 18 96 8d3a228a-1026-458b-9305-252733d0b5ad a=rtpmap:8 PCMA/8000 8d3a228a-1026-458b-9305-252733d0b5ad a=rtpmap:18 G729/8000 8d3a228a-1026-458b-9305-252733d0b5ad a=rtpmap:96 telephone-event/8000 8d3a228a-1026-458b-9305-252733d0b5ad a=fmtp:96 0-15 8d3a228a-1026-458b-9305-252733d0b5ad a=ptime:20 8d3a228a-1026-458b-9305-252733d0b5ad a=ptime:30 8d3a228a-1026-458b-9305-252733d0b5ad 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:47.992669 [DEBUG] sofia.c:7450 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) State Change CS_NEW -> CS_INIT 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:47.992669 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) State NEW 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:47.992669 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) Running State Change CS_INIT (Cur 1 Tot 33) 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.002668 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) State INIT 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.002668 [DEBUG] mod_sofia.c:90 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com SOFIA INIT 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.002668 [DEBUG] switch_core_state_machine.c:40 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Standard INIT 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.002668 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) State Change CS_INIT -> CS_ROUTING 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.002668 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) State INIT going to sleep 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.002668 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) Running State Change CS_ROUTING (Cur 1 Tot 33) 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.002668 [DEBUG] switch_channel.c:2249 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) Callstate Change DOWN -> RINGING 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.002668 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) State ROUTING 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.002668 [DEBUG] mod_sofia.c:143 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com SOFIA ROUTING 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.002668 [DEBUG] switch_core_state_machine.c:236 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Standard ROUTING 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.002668 [INFO] mod_dialplan_xml.c:637 Processing london.devserver.sytelco.com ->2200 in context public 8d3a228a-1026-458b-9305-252733d0b5ad Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com parsing [public->unloop] continue=false 8d3a228a-1026-458b-9305-252733d0b5ad Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false 8d3a228a-1026-458b-9305-252733d0b5ad Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false 8d3a228a-1026-458b-9305-252733d0b5ad Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com parsing [public->outside_call] continue=true 8d3a228a-1026-458b-9305-252733d0b5ad Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Absolute Condition [outside_call] 8d3a228a-1026-458b-9305-252733d0b5ad Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Action set(outside_call=true) 8d3a228a-1026-458b-9305-252733d0b5ad Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) 8d3a228a-1026-458b-9305-252733d0b5ad Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com parsing [public->call_debug] continue=true 8d3a228a-1026-458b-9305-252733d0b5ad Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never 8d3a228a-1026-458b-9305-252733d0b5ad Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com parsing [public->extensions_nailup] continue=false 8d3a228a-1026-458b-9305-252733d0b5ad Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Regex (PASS) [extensions_nailup] network_addr(10.0.0.146) =~ /10.0.0.146/ break=on-false 8d3a228a-1026-458b-9305-252733d0b5ad Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Regex (PASS) [extensions_nailup] destination_number(2200) =~ /^(\d{4})$/ break=on-false 8d3a228a-1026-458b-9305-252733d0b5ad Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Action export(dialed_extension=2200) 8d3a228a-1026-458b-9305-252733d0b5ad Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Action set(call_timeout=30) 8d3a228a-1026-458b-9305-252733d0b5ad Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Action bridge(user/${dialed_extension}@${caller_id_name}) 8d3a228a-1026-458b-9305-252733d0b5ad Dialplan: sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Action hangup() 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.002668 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) State Change CS_ROUTING -> CS_EXECUTE 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.002668 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) State ROUTING going to sleep 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.002668 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) Running State Change CS_EXECUTE (Cur 1 Tot 33) 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.002668 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) State EXECUTE 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.002668 [DEBUG] mod_sofia.c:198 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com SOFIA EXECUTE 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.002668 [DEBUG] switch_core_state_machine.c:328 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Standard EXECUTE 8d3a228a-1026-458b-9305-252733d0b5ad EXECUTE sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com set(outside_call=true) 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.002668 [DEBUG] mod_dptools.c:1530 SET sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com [outside_call]=[true] 8d3a228a-1026-458b-9305-252733d0b5ad EXECUTE sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com export(RFC2822_DATE=Tue, 13 Jun 2017 17:06:48 +0100) 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.002668 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Tue, 13 Jun 2017 17:06:48 +0100] 8d3a228a-1026-458b-9305-252733d0b5ad EXECUTE sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com export(dialed_extension=2200) 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.002668 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dialed_extension]=[2200] 8d3a228a-1026-458b-9305-252733d0b5ad EXECUTE sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com set(call_timeout=30) 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.002668 [DEBUG] mod_dptools.c:1530 SET sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com [call_timeout]=[30] 8d3a228a-1026-458b-9305-252733d0b5ad EXECUTE sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com bridge(user/2200@london.devserver.sytelco.com) 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.002668 [DEBUG] switch_channel.c:1250 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com EXPORTING[export_vars] [RFC2822_DATE]=[Tue, 13 Jun 2017 17:06:48 +0100] to event 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.002668 [DEBUG] switch_channel.c:1250 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com EXPORTING[export_vars] [dialed_extension]=[2200] to event 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.002668 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables 2017-06-13 17:06:48.052666 [CONSOLE] mod_xml_curl.c:323 XML response is in C:/Windows/TEMP/2905685b-9571-429b-ae87-d661dcb0a0bc.tmp.xml 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.062670 [DEBUG] switch_channel.c:1250 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com EXPORTING[export_vars] [RFC2822_DATE]=[Tue, 13 Jun 2017 17:06:48 +0100] to event 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.062670 [DEBUG] switch_channel.c:1250 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com EXPORTING[export_vars] [dialed_extension]=[2200] to event 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.062670 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:48.062670 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/2200@df7jal23ls0d.invalid [1ed73279-3e4e-414d-9143-d6c6f1bb1352] 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:48.062670 [DEBUG] mod_sofia.c:4818 (sofia/internal/2200@df7jal23ls0d.invalid) State Change CS_NEW -> CS_INIT 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:48.062670 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/2200@df7jal23ls0d.invalid) Running State Change CS_INIT (Cur 2 Tot 34) 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:48.062670 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/2200@df7jal23ls0d.invalid) State INIT 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:48.062670 [DEBUG] mod_sofia.c:90 sofia/internal/2200@df7jal23ls0d.invalid SOFIA INIT 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:48.062670 [DEBUG] sofia_glue.c:1264 sips:2200@10.1.0.41:58790;rtcweb-breaker=no;transport=wss Setting proxy route to sofia/internal/2200@df7jal23ls0d.invalid 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:48.062670 [DEBUG] sofia_glue.c:1295 sofia/internal/2200@df7jal23ls0d.invalid sending invite version: 1.6.17 git 0fc0946 2017-04-17 14:21:08Z 64bit 1ed73279-3e4e-414d-9143-d6c6f1bb1352 Local SDP: 1ed73279-3e4e-414d-9143-d6c6f1bb1352 v=0 1ed73279-3e4e-414d-9143-d6c6f1bb1352 o=FreeSWITCH 1497347900 1497347901 IN IP4 10.0.0.34 1ed73279-3e4e-414d-9143-d6c6f1bb1352 s=FreeSWITCH 1ed73279-3e4e-414d-9143-d6c6f1bb1352 c=IN IP4 10.0.0.34 1ed73279-3e4e-414d-9143-d6c6f1bb1352 t=0 0 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=msid-semantic: WMS DRYvfQD51qFR8xKidCQOKIZqx6MB1uuV 1ed73279-3e4e-414d-9143-d6c6f1bb1352 m=audio 22108 RTP/SAVPF 8 101 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=rtpmap:8 PCMA/8000 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=rtpmap:101 telephone-event/8000 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=fingerprint:sha-256 9F:F9:B2:1A:10:6A:EE:3C:33:45:D0:58:44:03:05:7A:20:9D:0B:63:74:B8:3C:DC:B3:AA:8B:82:35:26:F2:3C 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=setup:actpass 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=rtcp-mux 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=rtcp:22108 IN IP4 10.0.0.34 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=ssrc:1892802664 cname:KJpeKVpU3LpVj2qu 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=ssrc:1892802664 msid:DRYvfQD51qFR8xKidCQOKIZqx6MB1uuV a0 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=ssrc:1892802664 mslabel:DRYvfQD51qFR8xKidCQOKIZqx6MB1uuV 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=ssrc:1892802664 label:DRYvfQD51qFR8xKidCQOKIZqx6MB1uuVa0 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=ice-ufrag:yk9A2CQurT3y8oo9 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=ice-pwd:OSGllaBX1wrD5dLHKHQhqJyx 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=candidate:6918049260 1 udp 659136 10.0.0.34 22108 typ host generation 0 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=candidate:6918049260 2 udp 659136 10.0.0.34 22108 typ host generation 0 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=ptime:20 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=sendrecv 1ed73279-3e4e-414d-9143-d6c6f1bb1352 send 2065 bytes to wss/[10.1.0.41]:58790 at 16:06:48.067667: ------------------------------------------------------------------------ INVITE sip:2200@df7jal23ls0d.invalid;rtcweb-breaker=no;transport=wss SIP/2.0 Via: SIP/2.0/WSS 10.0.0.34:7443;branch=z9hG4bK5mmS7Ka2j1Dvp Route: ;rtcweb-breaker=no;transport=wss Max-Forwards: 69 From: "london.devserver.sytelco.com" ;tag=Q767mQpBKvU0j To: Call-ID: 2527af44-caf5-1235-1984-9d7e09c72572 CSeq: 108348940 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.6.17+git~20170417T142108Z~0fc0946461~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 871 X-FS-Support: update_display,send_info Remote-Party-ID: "london.devserver.sytelco.com" ;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 1497347900 1497347901 IN IP4 10.0.0.34 s=FreeSWITCH c=IN IP4 10.0.0.34 t=0 0 a=msid-semantic: WMS DRYvfQD51qFR8xKidCQOKIZqx6MB1uuV m=audio 22108 RTP/SAVPF 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fingerprint:sha-256 9F:F9:B2:1A:10:6A:EE:3C:33:45:D0:58:44:03:05:7A:20:9D:0B:63:74:B8:3C:DC:B3:AA:8B:82:35:26:F2:3C a=setup:actpass a=rtcp-mux a=rtcp:22108 IN IP4 10.0.0.34 a=ssrc:1892802664 cname:KJpeKVpU3LpVj2qu a=ssrc:1892802664 msid:DRYvfQD51qFR8xKidCQOKIZqx6MB1uuV a0 a=ssrc:1892802664 mslabel:DRYvfQD51qFR8xKidCQOKIZqx6MB1uuV a=ssrc:1892802664 label:DRYvfQD51qFR8xKidCQOKIZqx6MB1uuVa0 a=ice-ufrag:yk9A2CQurT3y8oo9 a=ice-pwd:OSGllaBX1wrD5dLHKHQhqJyx a=candidate:6918049260 1 udp 659136 10.0.0.34 22108 typ host generation 0 a=candidate:6918049260 2 udp 659136 10.0.0.34 22108 typ host generation 0 a=ptime:20 ------------------------------------------------------------------------ 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:48.062670 [DEBUG] switch_core_state_machine.c:40 sofia/internal/2200@df7jal23ls0d.invalid Standard INIT 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:48.062670 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/2200@df7jal23ls0d.invalid) State Change CS_INIT -> CS_ROUTING 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:48.062670 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/2200@df7jal23ls0d.invalid) State INIT going to sleep 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:48.062670 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/2200@df7jal23ls0d.invalid) Running State Change CS_ROUTING (Cur 2 Tot 34) 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:48.062670 [DEBUG] sofia.c:7048 Channel sofia/internal/2200@df7jal23ls0d.invalid entering state [calling][0] 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:48.062670 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/2200@df7jal23ls0d.invalid) State ROUTING 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:48.062670 [DEBUG] mod_sofia.c:143 sofia/internal/2200@df7jal23ls0d.invalid SOFIA ROUTING 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:48.062670 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/2200@df7jal23ls0d.invalid) State Change CS_ROUTING -> CS_CONSUME_MEDIA 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:48.062670 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/2200@df7jal23ls0d.invalid) State ROUTING going to sleep 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:48.062670 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/2200@df7jal23ls0d.invalid) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 34) 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:48.062670 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/2200@df7jal23ls0d.invalid) State CONSUME_MEDIA 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:48.062670 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/2200@df7jal23ls0d.invalid) State CONSUME_MEDIA going to sleep recv 395 bytes from wss/[10.1.0.41]:58790 at 16:06:48.081667: ------------------------------------------------------------------------ SIP/2.0 100 Trying (sent from the Transaction Layer) Via: SIP/2.0/WSS 10.0.0.34:7443;branch=z9hG4bK5mmS7Ka2j1Dvp From: "london.devserver.sytelco.com";tag=Q767mQpBKvU0j To: Call-ID: 2527af44-caf5-1235-1984-9d7e09c72572 CSeq: 108348940 INVITE Content-Length: 0 ------------------------------------------------------------------------ recv 525 bytes from wss/[10.1.0.41]:58790 at 16:06:48.114669: ------------------------------------------------------------------------ SIP/2.0 180 Ringing Via: SIP/2.0/WSS 10.0.0.34:7443;branch=z9hG4bK5mmS7Ka2j1Dvp From: "london.devserver.sytelco.com";tag=Q767mQpBKvU0j To: ;tag=Wr8bdHMXPuA9FKAkhxJr Contact: Call-ID: 2527af44-caf5-1235-1984-9d7e09c72572 CSeq: 108348940 INVITE Content-Length: 0 Allow: ACK, BYE, CANCEL, INVITE, MESSAGE, NOTIFY, OPTIONS, PRACK, REFER, UPDATE ------------------------------------------------------------------------ 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:48.112668 [DEBUG] sofia.c:7048 Channel sofia/internal/2200@df7jal23ls0d.invalid entering state [proceeding][180] 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:48.112668 [NOTICE] sofia.c:7156 Ring-Ready sofia/internal/2200@df7jal23ls0d.invalid! 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:48.112668 [DEBUG] switch_channel.c:3345 (sofia/internal/2200@df7jal23ls0d.invalid) Callstate Change DOWN -> RINGING 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.132669 [NOTICE] mod_sofia.c:2272 Ring-Ready sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com! 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.132669 [NOTICE] switch_ivr_originate.c:525 Ring Ready sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com! send 943 bytes to udp/[10.0.0.146]:5060 at 16:06:48.145669: ------------------------------------------------------------------------ SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.0.0.146:5060;branch=z9hG4bK4dbee997-5052-11e7-97ac-9a138dd73e1d;rport=5060 From: london.devserver.sytelco.com ;tag=ACU-18be-e7f2ccd2 To: 2200 ;tag=pyDFKv57NK5DQ Call-ID: 00447001-0000C3F8-59400D97-00000001@10.0.0.146 CSeq: 26500 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.6.17+git~20170417T142108Z~0fc0946461~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Length: 0 Remote-Party-ID: "Outbound Call" ;party=calling;privacy=off;screen=no ------------------------------------------------------------------------ 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:48.152668 [DEBUG] sofia.c:7048 Channel sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com entering state [early][180] recv 1846 bytes from wss/[10.1.0.41]:58790 at 16:06:53.837716: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/WSS 10.0.0.34:7443;branch=z9hG4bK5mmS7Ka2j1Dvp From: "london.devserver.sytelco.com";tag=Q767mQpBKvU0j To: ;tag=Wr8bdHMXPuA9FKAkhxJr Contact: Call-ID: 2527af44-caf5-1235-1984-9d7e09c72572 CSeq: 108348940 INVITE Content-Type: application/sdp Content-Length: 1292 Allow: ACK, BYE, CANCEL, INVITE, MESSAGE, NOTIFY, OPTIONS, PRACK, REFER, UPDATE v=0 o=- 5251170910027638000 2 IN IP4 127.0.0.1 s=Doubango Telecom - chrome t=0 0 a=msid-semantic: WMS 6IxRuwNx2omtA3zF3Zx8QkLBXwsrXKJxSg0Z m=audio 56341 UDP/TLS/RTP/SAVPF 8 101 c=IN IP4 81.139.175.134 a=rtcp:9 IN IP4 0.0.0.0 a=candidate:3891828076 1 udp 2122260223 10.1.0.41 56341 typ host generation 0 network-id 1 network-cost 10 a=candidate:2775935972 1 udp 1686052607 81.139.175.134 56341 typ srflx raddr 10.1.0.41 rport 56341 generation 0 network-id 1 network-cost 10 a=candidate:2775935972 1 udp 1686052607 80.229.34.139 56341 typ srflx raddr 10.1.0.41 rport 56341 generation 0 network-id 1 network-cost 10 a=candidate:2843437468 1 tcp 1518280447 10.1.0.41 9 typ host tcptype active generation 0 network-id 1 network-cost 10 a=ice-ufrag:w3tC a=ice-pwd:RGBx+5m4Kwu79vAA2r4Y6/q+ a=fingerprint:sha-256 49:2B:B4:95:65:7E:33:8C:07:54:09:E0:65:10:53:73:04:C0:4E:17:DE:21:85:1C:D0:9A:35:0E:98:5C:68:F4 a=setup:active a=mid:audio a=sendrecv a=rtcp-mux a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=ssrc:1017001704 cname:MMIn28bnaOKRkdSt a=ssrc:1017001704 msid:6IxRuwNx2omtA3zF3Zx8QkLBXwsrXKJxSg0Z a4e0e59c-af2d-44c9-93d5-1380d410a1b0 a=ssrc:1017001704 mslabel:6IxRuwNx2omtA3zF3Zx8QkLBXwsrXKJxSg0Z a=ssrc:1017001704 label:a4e0e59c-af2d-44c9-93d5-1380d410a1b0 ------------------------------------------------------------------------ 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [DEBUG] sofia.c:7048 Channel sofia/internal/2200@df7jal23ls0d.invalid entering state [completing][200] 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [DEBUG] sofia.c:7058 Remote SDP: 1ed73279-3e4e-414d-9143-d6c6f1bb1352 v=0 1ed73279-3e4e-414d-9143-d6c6f1bb1352 o=- 5251170910027638000 2 IN IP4 127.0.0.1 1ed73279-3e4e-414d-9143-d6c6f1bb1352 s=Doubango Telecom - chrome 1ed73279-3e4e-414d-9143-d6c6f1bb1352 t=0 0 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=msid-semantic: WMS 6IxRuwNx2omtA3zF3Zx8QkLBXwsrXKJxSg0Z 1ed73279-3e4e-414d-9143-d6c6f1bb1352 m=audio 56341 UDP/TLS/RTP/SAVPF 8 101 1ed73279-3e4e-414d-9143-d6c6f1bb1352 c=IN IP4 81.139.175.134 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=rtpmap:8 PCMA/8000 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=rtpmap:101 telephone-event/8000 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=rtcp:9 IN IP4 0.0.0.0 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=candidate:3891828076 1 udp 2122260223 10.1.0.41 56341 typ host generation 0 network-id 1 network-cost 10 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=candidate:2775935972 1 udp 1686052607 81.139.175.134 56341 typ srflx raddr 10.1.0.41 rport 56341 generation 0 network-id 1 network-cost 10 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=candidate:2775935972 1 udp 1686052607 80.229.34.139 56341 typ srflx raddr 10.1.0.41 rport 56341 generation 0 network-id 1 network-cost 10 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=candidate:2843437468 1 tcp 1518280447 10.1.0.41 9 typ host tcptype active generation 0 network-id 1 network-cost 10 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=ice-ufrag:w3tC 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=ice-pwd:RGBx+5m4Kwu79vAA2r4Y6/q+ 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=fingerprint:sha-256 49:2B:B4:95:65:7E:33:8C:07:54:09:E0:65:10:53:73:04:C0:4E:17:DE:21:85:1C:D0:9A:35:0E:98:5C:68:F4 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=setup:active 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=mid:audio 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=rtcp-mux 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=ssrc:1017001704 cname:MMIn28bnaOKRkdSt 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=ssrc:1017001704 msid:6IxRuwNx2omtA3zF3Zx8QkLBXwsrXKJxSg0Z a4e0e59c-af2d-44c9-93d5-1380d410a1b0 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=ssrc:1017001704 mslabel:6IxRuwNx2omtA3zF3Zx8QkLBXwsrXKJxSg0Z 1ed73279-3e4e-414d-9143-d6c6f1bb1352 a=ssrc:1017001704 label:a4e0e59c-af2d-44c9-93d5-1380d410a1b0 1ed73279-3e4e-414d-9143-d6c6f1bb1352 send 481 bytes to wss/[10.1.0.41]:58790 at 16:06:53.843728: ------------------------------------------------------------------------ ACK sips:2200@df7jal23ls0d.invalid;transport=wss SIP/2.0 Via: SIP/2.0/WSS 10.0.0.34:7443;branch=z9hG4bK6XDj9eU5Fa4ej Max-Forwards: 70 From: "london.devserver.sytelco.com" ;tag=Q767mQpBKvU0j To: ;tag=Wr8bdHMXPuA9FKAkhxJr Call-ID: 2527af44-caf5-1235-1984-9d7e09c72572 CSeq: 108348940 ACK Contact: Content-Length: 0 ------------------------------------------------------------------------ 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [DEBUG] sofia.c:7048 Channel sofia/internal/2200@df7jal23ls0d.invalid entering state [ready][200] 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [DEBUG] switch_core_media.c:4352 Set telephone-event payload to 101@8000 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [DEBUG] switch_core_media.c:3056 Set Codec sofia/internal/2200@df7jal23ls0d.invalid PCMA/8000 20 ms 160 samples 64000 bits 1 channels 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [DEBUG] switch_core_codec.c:111 sofia/internal/2200@df7jal23ls0d.invalid Original read codec set to PCMA:8 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [WARNING] switch_core_media.c:3434 NO candidate ACL defined, Defaulting to wan.auto 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [DEBUG] switch_core_media.c:3464 Save audio Candidate cid: 1 proto: udp type: host addr: 10.1.0.41:56341 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [DEBUG] switch_core_media.c:3464 Save audio Candidate cid: 1 proto: udp type: srflx addr: 81.139.175.134:56341 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [DEBUG] switch_core_media.c:3464 Save audio Candidate cid: 1 proto: udp type: srflx addr: 80.229.34.139:56341 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [DEBUG] switch_core_media.c:3506 Searching for rtp candidate. 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [DEBUG] switch_core_media.c:3511 Choose rtp candidate, index 1, 81.139.175.134:56341 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [DEBUG] switch_core_media.c:3285 sofia/internal/2200@df7jal23ls0d.invalid choosing family v4 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [DEBUG] switch_core_media.c:3522 Choose same candidate, index 0, for rtcp based on rtcp-mux attribute 81.139.175.134:56341 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [DEBUG] switch_core_media.c:3569 setting remote audio ice addr to index 1 81.139.175.134:56341 based on candidate 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [DEBUG] switch_core_media.c:3601 Setting remote rtcp audio addr to 81.139.175.134:56341 based on candidate 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [DEBUG] switch_core_media.c:4695 Set telephone-event payload to 101@8000 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [DEBUG] switch_core_media.c:4754 sofia/internal/2200@df7jal23ls0d.invalid Set 2833 dtmf send payload to 101 recv payload to 101 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [DEBUG] switch_core_media.c:6865 AUDIO RTP [sofia/internal/2200@df7jal23ls0d.invalid] 10.0.0.34 port 22108 -> 81.139.175.134 port 56341 codec: 8 ms: 20 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [DEBUG] switch_rtp.c:4096 Starting timer [soft] 160 bytes per 20ms 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [INFO] switch_core_media.c:7042 Activating Audio ICE 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [NOTICE] switch_rtp.c:4591 Activating RTP audio ICE: w3tC:yk9A2CQurT3y8oo9 81.139.175.134:56341 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [DEBUG] switch_core_media.c:7085 Activating RTCP PORT 56341 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [DEBUG] switch_rtp.c:4488 RTCP send rate is: 1000 and packet rate is: 20000 Remote Port: 56341 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [INFO] switch_core_media.c:7093 Skipping RTCP ICE (Same as RTP) 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [INFO] switch_rtp.c:3574 Activate RTP/RTCP audio DTLS server 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [INFO] switch_rtp.c:3723 Changing audio DTLS state from OFF to HANDSHAKE 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [DEBUG] switch_core_media.c:7166 sofia/internal/2200@df7jal23ls0d.invalid Set 2833 dtmf send payload to 101 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [DEBUG] switch_core_media.c:7173 sofia/internal/2200@df7jal23ls0d.invalid Set 2833 dtmf receive payload to 101 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [DEBUG] switch_core_media.c:7196 sofia/internal/2200@df7jal23ls0d.invalid Set rtp dtmf delay to 40 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [NOTICE] sofia.c:8182 Channel [sofia/internal/2200@df7jal23ls0d.invalid] has been answered 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.842725 [DEBUG] switch_channel.c:3772 (sofia/internal/2200@df7jal23ls0d.invalid) Callstate Change RINGING -> ACTIVE 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:53.872667 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:30:64000:1]/[opus:116:48000:20:0:1] 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:53.872667 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:30:64000:1]/[PCMU:0:8000:20:64000:1] 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:53.872667 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:30:64000:1]/[PCMA:8:8000:20:64000:1] 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:53.872667 [DEBUG] switch_core_media.c:4472 Audio Codec Compare [PCMA:8:8000:20:64000:1] is saved as a near-match 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:53.872667 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:30:8000:1]/[opus:116:48000:20:0:1] 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:53.872667 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:30:8000:1]/[PCMU:0:8000:20:64000:1] 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:53.872667 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:30:8000:1]/[PCMA:8:8000:20:64000:1] 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:53.872667 [DEBUG] switch_core_media.c:4352 Set telephone-event payload to 96@8000 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:53.872667 [DEBUG] switch_core_media.c:4543 Substituting codec PCMA@30i@8000h@1c 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:53.872667 [DEBUG] switch_core_media.c:3056 Set Codec sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com PCMA/8000 30 ms 240 samples 64000 bits 1 channels 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:53.872667 [DEBUG] switch_core_codec.c:111 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Original read codec set to PCMA:8 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:53.872667 [DEBUG] switch_core_media.c:4695 Set telephone-event payload to 96@8000 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:53.872667 [DEBUG] switch_core_media.c:4754 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Set 2833 dtmf send payload to 96 recv payload to 96 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:53.872667 [DEBUG] switch_core_media.c:6865 AUDIO RTP [sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com] 10.0.0.34 port 18212 -> 10.0.0.146 port 9022 codec: 8 ms: 30 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:53.872667 [DEBUG] switch_rtp.c:4096 Starting timer [soft] 240 bytes per 30ms 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:53.872667 [DEBUG] switch_core_media.c:7166 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Set 2833 dtmf send payload to 96 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:53.872667 [DEBUG] switch_core_media.c:7173 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Set 2833 dtmf receive payload to 96 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:53.872667 [DEBUG] switch_core_media.c:7196 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Set rtp dtmf delay to 40 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:53.872667 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com! 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:53.872667 [DEBUG] switch_channel.c:3473 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) Callstate Change RINGING -> EARLY 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:53.872667 [DEBUG] switch_core_media.c:6848 Audio params are unchanged for sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com. 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:53.872667 [DEBUG] mod_sofia.c:850 Local SDP sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com: 8d3a228a-1026-458b-9305-252733d0b5ad v=0 8d3a228a-1026-458b-9305-252733d0b5ad o=FreeSWITCH 1497351801 1497351802 IN IP4 10.0.0.34 8d3a228a-1026-458b-9305-252733d0b5ad s=FreeSWITCH 8d3a228a-1026-458b-9305-252733d0b5ad c=IN IP4 10.0.0.34 8d3a228a-1026-458b-9305-252733d0b5ad t=0 0 8d3a228a-1026-458b-9305-252733d0b5ad m=audio 18212 RTP/AVP 8 96 8d3a228a-1026-458b-9305-252733d0b5ad a=rtpmap:8 PCMA/8000 8d3a228a-1026-458b-9305-252733d0b5ad a=rtpmap:96 telephone-event/8000 8d3a228a-1026-458b-9305-252733d0b5ad a=fmtp:96 0-16 8d3a228a-1026-458b-9305-252733d0b5ad a=ptime:30 8d3a228a-1026-458b-9305-252733d0b5ad a=sendrecv 8d3a228a-1026-458b-9305-252733d0b5ad 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:53.872667 [NOTICE] switch_ivr_originate.c:3632 Channel [sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com] has been answered 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:53.872667 [DEBUG] switch_channel.c:3772 (sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com) Callstate Change EARLY -> ACTIVE 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:53.872667 [DEBUG] switch_ivr_originate.c:3690 Originate Resulted in Success: [sofia/internal/2200@df7jal23ls0d.invalid] send 1187 bytes to udp/[10.0.0.146]:5060 at 16:06:53.878667: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 10.0.0.146:5060;branch=z9hG4bK4dbee997-5052-11e7-97ac-9a138dd73e1d;rport=5060 From: london.devserver.sytelco.com ;tag=ACU-18be-e7f2ccd2 To: 2200 ;tag=pyDFKv57NK5DQ Call-ID: 00447001-0000C3F8-59400D97-00000001@10.0.0.146 CSeq: 26500 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.6.17+git~20170417T142108Z~0fc0946461~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 211 Remote-Party-ID: "Outbound Call" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1497351801 1497351802 IN IP4 10.0.0.34 s=FreeSWITCH c=IN IP4 10.0.0.34 t=0 0 m=audio 18212 RTP/AVP 8 96 a=rtpmap:8 PCMA/8000 a=rtpmap:96 telephone-event/8000 a=fmtp:96 0-16 a=ptime:30 ------------------------------------------------------------------------ 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:53.872667 [DEBUG] sofia.c:7048 Channel sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com entering state [completed][200] recv 423 bytes from udp/[10.0.0.146]:5060 at 16:06:53.880667: ------------------------------------------------------------------------ ACK sip:2200@10.0.0.34:5060;transport=udp SIP/2.0 From: london.devserver.sytelco.com ;tag=ACU-18be-e7f2ccd2 To: 2200 ;tag=pyDFKv57NK5DQ Max-Forwards: 70 Call-ID: 00447001-0000C3F8-59400D97-00000001@10.0.0.146 CSeq: 26500 ACK Content-Length: 0 Via: SIP/2.0/UDP 10.0.0.146:5060;branch=z9hG4bK51417e52-5052-11e7-97ac-9a138dd73e1d;rport ------------------------------------------------------------------------ 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:53.872667 [DEBUG] sofia.c:7048 Channel sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com entering state [ready][200] 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:53.882667 [DEBUG] switch_ivr_originate.c:3690 Originate Resulted in Success: [sofia/internal/2200@df7jal23ls0d.invalid] 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.882667 [DEBUG] switch_ivr_bridge.c:1601 (sofia/internal/2200@df7jal23ls0d.invalid) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.882667 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/2200@df7jal23ls0d.invalid) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 34) 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.882667 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/2200@df7jal23ls0d.invalid) State EXCHANGE_MEDIA 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.882667 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:53.973669 [DEBUG] switch_rtp.c:7229 Correct audio ip/port confirmed. 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:53.973669 [DEBUG] switch_core_io.c:1448 Engaging Write Buffer at 320 bytes to accommodate 320->320 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:54.062667 [NOTICE] switch_rtp.c:1278 Auto Changing audio stun/rtp/dtls port from 81.139.175.134:56341 to 10.1.0.41:56341 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:54.192669 [WARNING] switch_core_media.c:2475 [CBR]: Asynchronous PTIME not supported, changing our end from 30 to 20 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:54.202668 [INFO] switch_rtp.c:3185 Changing audio DTLS state from HANDSHAKE to SETUP 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:54.212669 [DEBUG] switch_core_media.c:2954 Changing Codec from PCMA@30ms@8000hz to PCMA@20ms@8000hz 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:54.222667 [INFO] switch_rtp.c:3094 audio Fingerprint Verified. 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:54.222667 [INFO] switch_rtp.c:3908 Activating audio Secure RTP SEND 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:54.222667 [INFO] switch_rtp.c:3886 Activating audio Secure RTP RECV 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:54.222667 [INFO] switch_rtp.c:3134 Changing audio DTLS state from SETUP to READY 2017-06-13 17:06:54.222667 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80 2017-06-13 17:06:54.222667 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80 1ed73279-3e4e-414d-9143-d6c6f1bb1352 2017-06-13 17:06:54.274668 [DEBUG] switch_rtp.c:1885 rtcp_stats_init: audio ssrc[1017001704] base_seq[765] 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:54.274668 [DEBUG] switch_rtp.c:3974 RE-Starting timer [soft] 160 bytes per 20ms 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:54.274668 [DEBUG] switch_core_media.c:3056 Set Codec sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com PCMA/8000 20 ms 160 samples 64000 bits 1 channels 8d3a228a-1026-458b-9305-252733d0b5ad 2017-06-13 17:06:54.274668 [DEBUG] switch_core_codec.c:123 sofia/internal/london.devserver.sytelco.com@sipserver.sytel.no-ip.com Original read codec replaced with PCMA:8