********************************************************
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 <sip:london.devserver.sytelco.com@sipserver.sytel.no-ip.com>;tag=ACU-1370-d75b057b
To: 2200 <sip:2200@10.0.0.145>
Contact: <sip:10.0.0.146>
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 <sip:london.devserver.sytelco.com@sipserver.sytel.no-ip.com>;tag=ACU-1370-d75b057b
To: 2200 <sip:2200@10.0.0.145>
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 <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 <sip:london.devserver.sytelco.com@sipserver.sytel.no-ip.com>;tag=ACU-1370-d75b057b
To: 2200 <sip:2200@10.0.0.145>;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" <sip:2200@10.0.0.145>;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 <sip:london.devserver.sytelco.com@sipserver.sytel.no-ip.com>;tag=ACU-1370-d75b057b
To: 2200 <sip:2200@10.0.0.145>;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 <sip:london.devserver.sytelco.com@sipserver.sytel.no-ip.com>;tag=ACU-18be-e7f2ccd2
To: 2200 <sip:2200@10.0.0.34>
Contact: <sip:10.0.0.146>
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 <sip:london.devserver.sytelco.com@sipserver.sytel.no-ip.com>;tag=ACU-18be-e7f2ccd2
To: 2200 <sip:2200@10.0.0.34>
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 <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: <sips:2200@10.1.0.41:58790>;rtcweb-breaker=no;transport=wss
Max-Forwards: 69
From: "london.devserver.sytelco.com" <sip:london.devserver.sytelco.com@london.devserver.sytelco.com>;tag=Q767mQpBKvU0j
To: <sip:2200@df7jal23ls0d.invalid;rtcweb-breaker=no;transport=wss>
Call-ID: 2527af44-caf5-1235-1984-9d7e09c72572
CSeq: 108348940 INVITE
Contact: <sip:mod_sofia@10.0.0.34:5060>
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" <sip:london.devserver.sytelco.com@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"<sip:london.devserver.sytelco.com@london.devserver.sytelco.com>;tag=Q767mQpBKvU0j
To: <sip:2200@df7jal23ls0d.invalid;rtcweb-breaker=no;transport=wss>
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"<sip:london.devserver.sytelco.com@london.devserver.sytelco.com>;tag=Q767mQpBKvU0j
To: <sip:2200@df7jal23ls0d.invalid;rtcweb-breaker=no;transport=wss>;tag=Wr8bdHMXPuA9FKAkhxJr
Contact: <sips:2200@df7jal23ls0d.invalid;transport=wss>
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 <sip:london.devserver.sytelco.com@sipserver.sytel.no-ip.com>;tag=ACU-18be-e7f2ccd2
To: 2200 <sip:2200@10.0.0.34>;tag=pyDFKv57NK5DQ
Call-ID: 00447001-0000C3F8-59400D97-00000001@10.0.0.146
CSeq: 26500 INVITE
Contact: <sip:2200@10.0.0.34:5060;transport=udp>
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" <sip:2200@10.0.0.34>;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"<sip:london.devserver.sytelco.com@london.devserver.sytelco.com>;tag=Q767mQpBKvU0j
To: <sip:2200@df7jal23ls0d.invalid;rtcweb-breaker=no;transport=wss>;tag=Wr8bdHMXPuA9FKAkhxJr
Contact: <sips:2200@df7jal23ls0d.invalid;transport=wss>
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" <sip:london.devserver.sytelco.com@london.devserver.sytelco.com>;tag=Q767mQpBKvU0j
To: <sip:2200@df7jal23ls0d.invalid;rtcweb-breaker=no;transport=wss>;tag=Wr8bdHMXPuA9FKAkhxJr
Call-ID: 2527af44-caf5-1235-1984-9d7e09c72572
CSeq: 108348940 ACK
Contact: <sip:mod_sofia@10.0.0.34:5060>
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 <sip:london.devserver.sytelco.com@sipserver.sytel.no-ip.com>;tag=ACU-18be-e7f2ccd2
To: 2200 <sip:2200@10.0.0.34>;tag=pyDFKv57NK5DQ
Call-ID: 00447001-0000C3F8-59400D97-00000001@10.0.0.146
CSeq: 26500 INVITE
Contact: <sip:2200@10.0.0.34:5060;transport=udp>
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" <sip:2200@10.0.0.34>;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 <sip:london.devserver.sytelco.com@sipserver.sytel.no-ip.com>;tag=ACU-18be-e7f2ccd2
To: 2200 <sip:2200@10.0.0.34>;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