------------------------------------------------------------------------
recv 1515 bytes from udp/[10.0.9.55]:5060 at 12:09:19.660430:
------------------------------------------------------------------------
INVITE sip:12134237681@office.nga911.com:15080 SIP/2.0
Record-Route: <sip:10.0.9.55;r2=on;lr=on;ftag=a1QtHc31jj5XH>
Record-Route: <sip:52.42.195.203:15080;transport=tcp;r2=on;lr=on;ftag=a1QtHc31jj5XH>
Record-Route: <sip:192.76.120.10;transport=tcp;r2=on;lr;ftag=a1QtHc31jj5XH>
Record-Route: <sip:10.15.5.6;transport=tcp;r2=on;lr;ftag=a1QtHc31jj5XH>
Via: SIP/2.0/UDP 10.0.9.55;branch=z9hG4bKe4ed.f1b16c318b2e697ff3f6ab8cd3140aa7.0;i=1
Via: SIP/2.0/TCP 192.76.120.10;branch=z9hG4bKe4ed.97ce71cee4cf5300aa275a07d41c3eac.0;i=cec
v:SIP/2.0/TCP 10.15.12.4:5082;received=10.15.12.4;rport=55742;branch=z9hG4bKvNceaS2aFHjNr
Max-Forwards:44
f:"Sergey Safarov"<sip:12013992990@sip.telnyx.com>;tag=a1QtHc31jj5XH
t:<sip:12134237681@office.nga911.com:15080>
i:17fab07d-716b-1236-7a88-02420a0f0c04
CSeq:117500215 INVITE
m:<sip:mod_sofia@10.15.12.4:5082;alias=10.15.12.4~55742~2>
Allow:INVITE,ACK,BYE,CANCEL,OPTIONS,MESSAGE,INFO,UPDATE,NOTIFY
k:timer,path,replaces
u:talk,hold,conference,refer
Privacy:none
c:application/sdp
Content-Disposition:session
l:333
P-Asserted-Identity:"Sergey Safarov"<sip:12013992990@sip.telnyx.com>
X-AUTH-IP: 192.76.120.10
X-AUTH-PORT: 36831
v=0
o=Telnyx 1515647013 1515647014 IN IP4 64.16.248.242
s=Telnyx
c=IN IP4 64.16.248.242
t=0 0
m=audio 25546 RTP/AVP 9 0 8 18 101 13
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
------------------------------------------------------------------------
send 865 bytes to udp/[10.0.9.55]:5060 at 12:09:19.660679:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.0.9.55;branch=z9hG4bKe4ed.f1b16c318b2e697ff3f6ab8cd3140aa7.0;i=1
Via: SIP/2.0/TCP 192.76.120.10;branch=z9hG4bKe4ed.97ce71cee4cf5300aa275a07d41c3eac.0;i=cec
v:SIP/2.0/TCP 10.15.12.4:5082;received=10.15.12.4;rport=55742;branch=z9hG4bKvNceaS2aFHjNr
Record-Route: <sip:10.0.9.55;r2=on;lr=on;ftag=a1QtHc31jj5XH>
Record-Route: <sip:52.42.195.203:15080;transport=tcp;r2=on;lr=on;ftag=a1QtHc31jj5XH>
Record-Route: <sip:192.76.120.10;transport=tcp;r2=on;lr;ftag=a1QtHc31jj5XH>
Record-Route: <sip:10.15.5.6;transport=tcp;r2=on;lr;ftag=a1QtHc31jj5XH>
f:"Sergey Safarov"<sip:12013992990@sip.telnyx.com>;tag=a1QtHc31jj5XH
t:<sip:12134237681@office.nga911.com:15080>
i:17fab07d-716b-1236-7a88-02420a0f0c04
CSeq:117500215 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.6.19+git-20171224T074649Z~f858a27ad1~64bit
Content-Length: 0
------------------------------------------------------------------------
2018-01-11 12:09:19.655466 [NOTICE] switch_channel.c:1104 New Channel sofia/external-kamailio/12013992990@sip.telnyx.com [5e07cf5b-2b87-4075-8430-34de18f707c4]
2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:584 (sofia/external-kamailio/12013992990@sip.telnyx.com) Running State Change CS_NEW (Cur 2 Tot 356)
2018-01-11 12:09:19.655466 [DEBUG] sofia.c:9873 sofia/external-kamailio/12013992990@sip.telnyx.com receiving invite from 10.0.9.55:5060 version: 1.6.19+git git f858a27 2017-12-24 07:46:49Z 64bit
2018-01-11 12:09:19.655466 [DEBUG] sofia.c:7084 Channel sofia/external-kamailio/12013992990@sip.telnyx.com entering state [received][100]
2018-01-11 12:09:19.655466 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=Telnyx 1515647013 1515647014 IN IP4 64.16.248.242
s=Telnyx
c=IN IP4 64.16.248.242
t=0 0
m=audio 25546 RTP/AVP 9 0 8 18 101 13
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
2018-01-11 12:09:19.655466 [DEBUG] sofia.c:7486 (sofia/external-kamailio/12013992990@sip.telnyx.com) State Change CS_NEW -> CS_INIT
2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:603 (sofia/external-kamailio/12013992990@sip.telnyx.com) State NEW
2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:584 (sofia/external-kamailio/12013992990@sip.telnyx.com) Running State Change CS_INIT (Cur 2 Tot 356)
2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:627 (sofia/external-kamailio/12013992990@sip.telnyx.com) State INIT
2018-01-11 12:09:19.655466 [DEBUG] mod_sofia.c:90 sofia/external-kamailio/12013992990@sip.telnyx.com SOFIA INIT
2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:40 sofia/external-kamailio/12013992990@sip.telnyx.com Standard INIT
2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:48 (sofia/external-kamailio/12013992990@sip.telnyx.com) State Change CS_INIT -> CS_ROUTING
2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:627 (sofia/external-kamailio/12013992990@sip.telnyx.com) State INIT going to sleep
2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:584 (sofia/external-kamailio/12013992990@sip.telnyx.com) Running State Change CS_ROUTING (Cur 2 Tot 356)
2018-01-11 12:09:19.655466 [DEBUG] switch_channel.c:2249 (sofia/external-kamailio/12013992990@sip.telnyx.com) Callstate Change DOWN -> RINGING
2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:643 (sofia/external-kamailio/12013992990@sip.telnyx.com) State ROUTING
2018-01-11 12:09:19.655466 [DEBUG] mod_sofia.c:143 sofia/external-kamailio/12013992990@sip.telnyx.com SOFIA ROUTING
2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:236 sofia/external-kamailio/12013992990@sip.telnyx.com Standard ROUTING
2018-01-11 12:09:19.655466 [INFO] mod_dialplan_xml.c:637 Processing Sergey Safarov <12013992990>->12134237681 in context e911
Dialplan: sofia/external-kamailio/12013992990@sip.telnyx.com parsing [e911->911] continue=false
Dialplan: sofia/external-kamailio/12013992990@sip.telnyx.com Regex (PASS) [911] destination_number(12134237681) =~ /^1(\d{10})$/ break=on-false
Dialplan: sofia/external-kamailio/12013992990@sip.telnyx.com Action set(sip_nat_detected=false)
Dialplan: sofia/external-kamailio/12013992990@sip.telnyx.com Action python(dialplan)
2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:286 (sofia/external-kamailio/12013992990@sip.telnyx.com) State Change CS_ROUTING -> CS_EXECUTE
2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:643 (sofia/external-kamailio/12013992990@sip.telnyx.com) State ROUTING going to sleep
2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:584 (sofia/external-kamailio/12013992990@sip.telnyx.com) Running State Change CS_EXECUTE (Cur 2 Tot 356)
2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:650 (sofia/external-kamailio/12013992990@sip.telnyx.com) State EXECUTE
2018-01-11 12:09:19.655466 [DEBUG] mod_sofia.c:198 sofia/external-kamailio/12013992990@sip.telnyx.com SOFIA EXECUTE
2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:328 sofia/external-kamailio/12013992990@sip.telnyx.com Standard EXECUTE
EXECUTE sofia/external-kamailio/12013992990@sip.telnyx.com set(sip_nat_detected=false)
2018-01-11 12:09:19.655466 [DEBUG] mod_dptools.c:1548 SET sofia/external-kamailio/12013992990@sip.telnyx.com [sip_nat_detected]=[false]
EXECUTE sofia/external-kamailio/12013992990@sip.telnyx.com python(dialplan)
2018-01-11 12:09:19.655466 [NOTICE] mod_python.c:212 Invoking py module: dialplan
2018-01-11 12:09:19.655466 [DEBUG] mod_python.c:283 Call python script
2018-01-11 12:09:19.655466 [DEBUG] switch_cpp.cpp:1112 sofia/external-kamailio/12013992990@sip.telnyx.com destroy/unlink session from object
EXECUTE sofia/external-kamailio/12013992990@sip.telnyx.com info()
2018-01-11 12:09:19.655466 [INFO] mod_dptools.c:1761 CHANNEL_DATA:
Channel-State: [CS_EXECUTE]
Channel-Call-State: [RINGING]
Channel-State-Number: [4]
Channel-Name: [sofia/external-kamailio/12013992990@sip.telnyx.com]
Unique-ID: [5e07cf5b-2b87-4075-8430-34de18f707c4]
Call-Direction: [inbound]
Presence-Call-Direction: [inbound]
Channel-HIT-Dialplan: [true]
Channel-Call-UUID: [5e07cf5b-2b87-4075-8430-34de18f707c4]
Answer-State: [ringing]
Caller-Direction: [inbound]
Caller-Logical-Direction: [inbound]
Caller-Username: [12013992990]
Caller-Dialplan: [XML]
Caller-Caller-ID-Name: [Sergey Safarov]
Caller-Caller-ID-Number: [12013992990]
Caller-Orig-Caller-ID-Name: [Sergey Safarov]
Caller-Orig-Caller-ID-Number: [12013992990]
Caller-Network-Addr: [10.0.9.55]
Caller-ANI: [12013992990]
Caller-Destination-Number: [12134237681]
Caller-Unique-ID: [5e07cf5b-2b87-4075-8430-34de18f707c4]
Caller-Source: [mod_sofia]
Caller-Context: [e911]
Caller-Channel-Name: [sofia/external-kamailio/12013992990@sip.telnyx.com]
Caller-Profile-Index: [1]
Caller-Profile-Created-Time: [1515672559655466]
Caller-Channel-Created-Time: [1515672559655466]
Caller-Channel-Answered-Time: [0]
Caller-Channel-Progress-Time: [0]
Caller-Channel-Progress-Media-Time: [0]
Caller-Channel-Hangup-Time: [0]
Caller-Channel-Transfer-Time: [0]
Caller-Channel-Resurrect-Time: [0]
Caller-Channel-Bridged-Time: [0]
Caller-Channel-Last-Hold: [0]
Caller-Channel-Hold-Accum: [0]
Caller-Screen-Bit: [true]
Caller-Privacy-Hide-Name: [false]
Caller-Privacy-Hide-Number: [false]
variable_direction: [inbound]
variable_uuid: [5e07cf5b-2b87-4075-8430-34de18f707c4]
variable_session_id: [356]
variable_sip_from_user: [12013992990]
variable_sip_from_uri: [12013992990@sip.telnyx.com]
variable_sip_from_host: [sip.telnyx.com]
variable_video_media_flow: [sendrecv]
variable_audio_media_flow: [sendrecv]
variable_channel_name: [sofia/external-kamailio/12013992990@sip.telnyx.com]
variable_sip_call_id: [17fab07d-716b-1236-7a88-02420a0f0c04]
variable_ep_codec_string: [mod_spandsp.G722@8000h@20i@64000b,CORE_PCM_MODULE.PCMU@8000h@20i@64000b,CORE_PCM_MODULE.PCMA@8000h@20i@64000b]
variable_sip_local_network_addr: [10.0.9.50]
variable_sip_network_ip: [10.0.9.55]
variable_sip_network_port: [5060]
variable_sip_invite_stamp: [1515672559655466]
variable_sip_received_ip: [10.0.9.55]
variable_sip_received_port: [5060]
variable_sip_via_protocol: [udp]
variable_sip_from_user_stripped: [12013992990]
variable_sip_from_tag: [a1QtHc31jj5XH]
variable_sofia_profile_name: [external-kamailio]
variable_recovery_profile_name: [external-kamailio]
variable_sip_P-Asserted-Identity: [12013992990]
variable_sip_cid_type: [pid]
variable_sip_invite_route_uri: [<sip:10.0.9.55;r2=on;lr=on;ftag=a1QtHc31jj5XH>,<sip:52.42.195.203:15080;transport=tcp;r2=on;lr=on;ftag=a1QtHc31jj5XH>,<sip:192.76.120.10;transport=tcp;r2=on;lr;ftag=a1QtHc31jj5XH>,<sip:10.15.5.6;transport=tcp;r2=on;lr;ftag=a1QtHc31jj5XH>]
variable_sip_invite_record_route: [<sip:10.15.5.6;transport=tcp;r2=on;lr;ftag=a1QtHc31jj5XH>,<sip:192.76.120.10;transport=tcp;r2=on;lr;ftag=a1QtHc31jj5XH>,<sip:52.42.195.203:15080;transport=tcp;r2=on;lr=on;ftag=a1QtHc31jj5XH>,<sip:10.0.9.55;r2=on;lr=on;ftag=a1QtHc31jj5XH>]
variable_sip_full_via: [SIP/2.0/UDP 10.0.9.55;branch=z9hG4bKe4ed.f1b16c318b2e697ff3f6ab8cd3140aa7.0;i=1,SIP/2.0/TCP 192.76.120.10;branch=z9hG4bKe4ed.97ce71cee4cf5300aa275a07d41c3eac.0;i=cec,SIP/2.0/TCP 10.15.12.4:5082;received=10.15.12.4;rport=55742;branch=z9hG4bKvNceaS2aFHjNr]
variable_sip_recover_via: [SIP/2.0/UDP 10.0.9.55;branch=z9hG4bKe4ed.f1b16c318b2e697ff3f6ab8cd3140aa7.0;i=1,SIP/2.0/TCP 192.76.120.10;branch=z9hG4bKe4ed.97ce71cee4cf5300aa275a07d41c3eac.0;i=cec,SIP/2.0/TCP 10.15.12.4:5082;received=10.15.12.4;rport=55742;branch=z9hG4bKvNceaS2aFHjNr]
variable_sip_from_display: [Sergey Safarov]
variable_sip_full_from: ["Sergey Safarov" <sip:12013992990@sip.telnyx.com>;tag=a1QtHc31jj5XH]
variable_sip_full_to: [<sip:12134237681@office.nga911.com:15080>]
variable_sip_allow: [INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, NOTIFY]
variable_sip_req_user: [12134237681]
variable_sip_req_port: [15080]
variable_sip_req_uri: [12134237681@office.nga911.com:15080]
variable_sip_req_host: [office.nga911.com]
variable_sip_to_user: [12134237681]
variable_sip_to_port: [15080]
variable_sip_to_uri: [12134237681@office.nga911.com:15080]
variable_sip_to_host: [office.nga911.com]
variable_sip_contact_params: [alias=10.15.12.4~55742~2]
variable_sip_contact_user: [mod_sofia]
variable_sip_contact_port: [5082]
variable_sip_contact_uri: [mod_sofia@10.15.12.4:5082]
variable_sip_contact_host: [10.15.12.4]
variable_rtp_use_codec_string: [OPUS,G722,PCMU,PCMA,VP8]
variable_sip_via_host: [10.0.9.55]
variable_max_forwards: [44]
variable_sip_Privacy: [none]
variable_sip_h_X-AUTH-IP: [192.76.120.10]
variable_sip_h_X-AUTH-PORT: [36831]
variable_switch_r_sdp: [v=0
o=Telnyx 1515647013 1515647014 IN IP4 64.16.248.242
s=Telnyx
c=IN IP4 64.16.248.242
t=0 0
m=audio 25546 RTP/AVP 9 0 8 18 101 13
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
]
variable_endpoint_disposition: [DELAYED NEGOTIATION]
variable_DP_MATCH: [ARRAY::12134237681|:2134237681]
variable_call_uuid: [5e07cf5b-2b87-4075-8430-34de18f707c4]
variable_sip_nat_detected: [false]
variable_current_application: [info]
2018-01-11 12:09:19.655466 [NOTICE] switch_core_session.c:1683 Session 354 (sofia/external-kamailio/12013992990@sip.telnyx.com) Ended
2018-01-11 12:09:19.655466 [NOTICE] switch_core_session.c:1687 Close Channel sofia/external-kamailio/12013992990@sip.telnyx.com [CS_DESTROY]
2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:741 (sofia/external-kamailio/12013992990@sip.telnyx.com) Running State Change CS_DESTROY (Cur 1 Tot 356)
2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:751 (sofia/external-kamailio/12013992990@sip.telnyx.com) State DESTROY
2018-01-11 12:09:19.655466 [DEBUG] mod_sofia.c:343 sofia/external-kamailio/12013992990@sip.telnyx.com SOFIA DESTROY
2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:181 sofia/external-kamailio/12013992990@sip.telnyx.com Standard DESTROY
2018-01-11 12:09:19.655466 [DEBUG] switch_core_state_machine.c:751 (sofia/external-kamailio/12013992990@sip.telnyx.com) State DESTROY going to sleep
2018-01-11 12:09:19.895537 [INFO] switch_cpp.cpp:1365 token: eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJzdWIiOjEyOCwiaXNzIjoiaHR0cHM6Ly9jc3AubmdhOTExLmNvbS9nZWFyX2FwaS9hdXRoZW50aWNhdGUiLCJpYXQiOjE1MTU2NzI1NTksImV4cCI6MTUxNTczMjU1OSwibmJmIjoxNTE1NjcyNTU5LCJqdGkiOiJzeDRJNm9BV2RqWDZ3elg1In0.qirCUoGn5nm7Ubf4WSytFX9Aq7AelXS98rUMPtyz2HY
2018-01-11 12:09:19.895537 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('csp_token', 'eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9.eyJzdWIiOjEyOCwiaXNzIjoiaHR0cHM6Ly9jc3AubmdhOTExLmNvbS9nZWFyX2FwaS9hdXRoZW50aWNhdGUiLCJpYXQiOjE1MTU2NzI1NTksImV4cCI6MTUxNTczMjU1OSwibmJmIjoxNTE1NjcyNTU5LCJqdGkiOiJzeDRJNm9BV2RqWDZ3elg1In0.qirCUoGn5nm7Ubf4WSytFX9Aq7AelXS98rUMPtyz2HY')
2018-01-11 12:09:20.115447 [INFO] switch_cpp.cpp:1365 esinetEntryRoutes url: http://csp.nga911.com/api/
esinetEntryRoutes/entry/12134237681
2018-01-11 12:09:20.115447 [INFO] switch_cpp.cpp:1365 esinetEntryRoutes: {u'message': u'Entry Route retrieval failed.', u'data': [], u'success': False}
2018-01-11 12:09:20.115447 [DEBUG] switch_core_session.c:2647 Application playback Requires media! pre_answering channel sofia/external-kamailio/12013992990@sip.telnyx.com
2018-01-11 12:09:20.115447 [INFO] switch_core_session.c:2649 Sending early media
2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1]
2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1]
2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:3061 Set Codec sofia/external-kamailio/12013992990@sip.telnyx.com G722/8000 20 ms 160 samples 64000 bits 1 channels
2018-01-11 12:09:20.115447 [DEBUG] switch_core_codec.c:111 sofia/external-kamailio/12013992990@sip.telnyx.com Original read codec set to G722:9
2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:4767 sofia/external-kamailio/12013992990@sip.telnyx.com Set 2833 dtmf send payload to 101 recv payload to 101
2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/external-kamailio/12013992990@sip.telnyx.com] 172.18.0.12 port 18352 -> 64.16.248.242 port 25546 codec: 9 ms: 20
2018-01-11 12:09:20.115447 [DEBUG] switch_rtp.c:4137 Starting timer [soft] 160 bytes per 20ms
2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:7180 sofia/external-kamailio/12013992990@sip.telnyx.com Set 2833 dtmf send payload to 101
2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:7187 sofia/external-kamailio/12013992990@sip.telnyx.com Set 2833 dtmf receive payload to 101
2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:7210 sofia/external-kamailio/12013992990@sip.telnyx.com Set rtp dtmf delay to 40
2018-01-11 12:09:20.115447 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external-kamailio/12013992990@sip.telnyx.com!
2018-01-11 12:09:20.115447 [DEBUG] switch_channel.c:3474 (sofia/external-kamailio/12013992990@sip.telnyx.com) Callstate Change RINGING -> EARLY
2018-01-11 12:09:20.115447 [DEBUG] switch_core_media.c:6861 Audio params are unchanged for sofia/external-kamailio/12013992990@sip.telnyx.com.
2018-01-11 12:09:20.115447 [DEBUG] mod_sofia.c:2364 Ring SDP:
v=0
o=FreeSWITCH 1515654208 1515654209 IN IP4 34.214.12.24
s=FreeSWITCH
c=IN IP4 34.214.12.24
t=0 0
m=audio 18352 RTP/AVP 9 101
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
EXECUTE sofia/external-kamailio/12013992990@sip.telnyx.com playback(error)
2018-01-11 12:09:20.115447 [ERR] mod_native_file.c:74 Error opening /usr/share/freeswitch/sounds/en/us/callie/error.G722
send 1502 bytes to udp/[10.0.9.55]:5060 at 12:09:20.121044:
------------------------------------------------------------------------
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 10.0.9.55;branch=z9hG4bKe4ed.f1b16c318b2e697ff3f6ab8cd3140aa7.0;i=1
Via: SIP/2.0/TCP 192.76.120.10;branch=z9hG4bKe4ed.97ce71cee4cf5300aa275a07d41c3eac.0;i=cec
v:SIP/2.0/TCP 10.15.12.4:5082;received=10.15.12.4;rport=55742;branch=z9hG4bKvNceaS2aFHjNr
Record-Route: <sip:10.0.9.55;r2=on;lr=on;ftag=a1QtHc31jj5XH>
Record-Route: <sip:52.42.195.203:15080;transport=tcp;r2=on;lr=on;ftag=a1QtHc31jj5XH>
Record-Route: <sip:192.76.120.10;transport=tcp;r2=on;lr;ftag=a1QtHc31jj5XH>
Record-Route: <sip:10.15.5.6;transport=tcp;r2=on;lr;ftag=a1QtHc31jj5XH>
f:"Sergey Safarov"<sip:12013992990@sip.telnyx.com>;tag=a1QtHc31jj5XH
To: <sip:12134237681@office.nga911.com:15080>;tag=jHa17jcp7XrtH
i:17fab07d-716b-1236-7a88-02420a0f0c04
CSeq:117500215 INVITE
Contact: <sip:12134237681@10.0.9.50:12000;transport=udp>
User-Agent: FreeSWITCH-mod_sofia/1.6.19+git-20171224T074649Z~f858a27ad1~64bit
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 220
P-Asserted-Identity: "12134237681" <sip:12134237681@office.nga911.com>
v=0
o=FreeSWITCH 1515654208 1515654209 IN IP4 34.214.12.24
s=FreeSWITCH
c=IN IP4 34.214.12.24
t=0 0
m=audio 18352 RTP/AVP 9 101
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
------------------------------------------------------------------------
2018-01-11 12:09:20.115447 [ERR] mod_sndfile.c:204 Error Opening File [/usr/share/freeswitch/sounds/en/us/callie/error.wav] [System error : No such file or directory.]
2018-01-11 12:09:20.115447 [DEBUG] sofia.c:7084 Channel sofia/external-kamailio/12013992990@sip.telnyx.com entering state [early][183]
2018-01-11 12:09:20.115447 [DEBUG] mod_python.c:286 Finished calling python script
2018-01-11 12:09:20.115447 [NOTICE] switch_core_state_machine.c:385 sofia/external-kamailio/12013992990@sip.telnyx.com has executed the last dialplan instruction, hanging up.
2018-01-11 12:09:20.115447 [NOTICE] switch_core_state_machine.c:387 Hangup sofia/external-kamailio/12013992990@sip.telnyx.com [CS_EXECUTE] [NORMAL_CLEARING]
2018-01-11 12:09:20.115447 [DEBUG] switch_core_state_machine.c:650 (sofia/external-kamailio/12013992990@sip.telnyx.com) State EXECUTE going to sleep
2018-01-11 12:09:20.115447 [DEBUG] switch_core_state_machine.c:584 (sofia/external-kamailio/12013992990@sip.telnyx.com) Running State Change CS_HANGUP (Cur 1 Tot 356)
2018-01-11 12:09:20.115447 [DEBUG] switch_core_state_machine.c:850 (sofia/external-kamailio/12013992990@sip.telnyx.com) Callstate Change EARLY -> HANGUP
2018-01-11 12:09:20.115447 [DEBUG] switch_core_state_machine.c:852 (sofia/external-kamailio/12013992990@sip.telnyx.com) State HANGUP
2018-01-11 12:09:20.115447 [DEBUG] mod_sofia.c:438 Channel sofia/external-kamailio/12013992990@sip.telnyx.com hanging up, cause: NORMAL_CLEARING
2018-01-11 12:09:20.115447 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 480
2018-01-11 12:09:20.115447 [DEBUG] switch_core_state_machine.c:60 sofia/external-kamailio/12013992990@sip.telnyx.com Standard HANGUP, cause: NORMAL_CLEARING
2018-01-11 12:09:20.115447 [DEBUG] switch_core_state_machine.c:852 (sofia/external-kamailio/12013992990@sip.telnyx.com) State HANGUP going to sleep
2018-01-11 12:09:20.115447 [DEBUG] switch_core_state_machine.c:619 (sofia/external-kamailio/12013992990@sip.telnyx.com) State Change CS_HANGUP -> CS_REPORTING
2018-01-11 12:09:20.115447 [DEBUG] switch_core_state_machine.c:584 (sofia/external-kamailio/12013992990@sip.telnyx.com) Running State Change CS_REPORTING (Cur 1 Tot 356)
send 910 bytes to udp/[10.0.9.55]:5060 at 12:09:20.121884:
------------------------------------------------------------------------
SIP/2.0 480 Temporarily Unavailable
Via: SIP/2.0/UDP 10.0.9.55;branch=z9hG4bKe4ed.f1b16c318b2e697ff3f6ab8cd3140aa7.0;i=1
Via: SIP/2.0/TCP 192.76.120.10;branch=z9hG4bKe4ed.97ce71cee4cf5300aa275a07d41c3eac.0;i=cec
v:SIP/2.0/TCP 10.15.12.4:5082;received=10.15.12.4;rport=55742;branch=z9hG4bKvNceaS2aFHjNr
Max-Forwards: 44
f:"Sergey Safarov"<sip:12013992990@sip.telnyx.com>;tag=a1QtHc31jj5XH
To: <sip:12134237681@office.nga911.com:15080>;tag=jHa17jcp7XrtH
i:17fab07d-716b-1236-7a88-02420a0f0c04
CSeq:117500215 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.6.19+git-20171224T074649Z~f858a27ad1~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, refer
Reason: Q.850;cause=16;text="NORMAL_CLEARING"
Content-Length: 0
P-Asserted-Identity: "12134237681" <sip:12134237681@office.nga911.com>
------------------------------------------------------------------------
2018-01-11 12:09:20.115447 [DEBUG] switch_core_state_machine.c:938 (sofia/external-kamailio/12013992990@sip.telnyx.com) State REPORTING
recv 359 bytes from udp/[10.0.9.55]:5060 at 12:09:20.122573:
------------------------------------------------------------------------
ACK sip:12134237681@office.nga911.com:15080 SIP/2.0
Via: SIP/2.0/UDP 10.0.9.55;branch=z9hG4bKe4ed.f1b16c318b2e697ff3f6ab8cd3140aa7.0;i=1
Max-Forwards:44
f:"Sergey Safarov"<sip:12013992990@sip.telnyx.com>;tag=a1QtHc31jj5XH
To: <sip:12134237681@office.nga911.com:15080>;tag=jHa17jcp7XrtH
i:17fab07d-716b-1236-7a88-02420a0f0c04
CSeq:117500215 ACK
l: 0
------------------------------------------------------------------------
2018-01-11 12:09:20.375470 [ERR] mod_xml_cdr.c:395 Got error [500] posting to web server [https://csp.nga911.com/call/LogXML]
2018-01-11 12:09:20.375470 [ERR] mod_xml_cdr.c:402 Retry will be with url [https://csp.nga911.com/call/LogXML]
2018-01-11 12:09:22.725466 [NOTICE] sofia_reg.c:448 Registering kazoo
send 822 bytes to udp/[52.42.195.203]:5060 at 12:09:22.745610:
------------------------------------------------------------------------
REGISTER sip:node1.nga911.com;transport=udp SIP/2.0
Via: SIP/2.0/UDP 52.24.72.57:5080;rport;branch=z9hG4bK86raX05cQ8gae
Max-Forwards: 70
From: <sip:queries1@node1.nga911.com>;tag=8XQ4Za3H2tD8g
To: <sip:queries1@node1.nga911.com>
Call-ID: 1268c844-60be-4a27-9325-bb3155eec8af
CSeq: 117500202 REGISTER
Contact: <sip:gw+kazoo@52.24.72.57:5080;transport=udp;gw=kazoo>
Expires: 30
User-Agent: FreeSWITCH-mod_sofia/1.6.19+git-20171224T074649Z~f858a27ad1~64bit
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Authorization: Digest username="queries1", realm="node1.nga911.com", nonce="WldU3FpXU7Ca5zf6SMinI2t36d3oUXlW", algorithm=MD5, uri="sip:node1.nga911.com;transport=udp", response="21e4c96c435809ed68656ef92732a1c7"
Content-Length: 0
------------------------------------------------------------------------
recv 440 bytes from udp/[52.42.195.203]:5060 at 12:09:22.767369:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 52.24.72.57:5080;rport=5080;branch=z9hG4bK86raX05cQ8gae;received=34.214.12.24
From: <sip:queries1@node1.nga911.com>;tag=8XQ4Za3H2tD8g
To: <sip:queries1@node1.nga911.com>;tag=bdded40c8142006f90af49be63d6cf32-6b23
Call-ID: 1268c844-60be-4a27-9325-bb3155eec8af
CSeq: 117500202 REGISTER
Contact: <sip:gw+kazoo@52.24.72.57:5080;transport=udp;gw=kazoo>;expires=300
Supported: outbound
Content-Length: 0
------------------------------------------------------------------------
2018-01-11 12:09:22.765513 [DEBUG] sofia_reg.c:2435 Changing expire time to 300 by request of proxy sip:node1.nga911.com
2018-01-11 12:09:22.845469 [ERR] mod_xml_cdr.c:395 Got error [500] posting to web server [https://csp.nga911.com/call/LogXML]
2018-01-11 12:09:22.845469 [ERR] mod_xml_cdr.c:402 Retry will be with url [https://csp.nga911.com/call/LogXML]
2018-01-11 12:09:25.065472 [ERR] mod_xml_cdr.c:395 Got error [500] posting to web server [https://csp.nga911.com/call/LogXML]
2018-01-11 12:09:25.065472 [ERR] mod_xml_cdr.c:402 Retry will be with url [https://csp.nga911.com/call/LogXML]
2018-01-11 12:09:27.355470 [ERR] mod_xml_cdr.c:395 Got error [500] posting to web server [https://csp.nga911.com/call/LogXML]
2018-01-11 12:09:27.355470 [ERR] mod_xml_cdr.c:402 Retry will be with url [https://csp.nga911.com/call/LogXML]
2018-01-11 12:09:27.355470 [ERR] mod_xml_cdr.c:418 Unable to post to web server, writing to file
2018-01-11 12:09:27.355470 [DEBUG] switch_core_state_machine.c:174 sofia/external-kamailio/12013992990@sip.telnyx.com Standard REPORTING, cause: NORMAL_CLEARING
2018-01-11 12:09:27.355470 [DEBUG] switch_core_state_machine.c:938 (sofia/external-kamailio/12013992990@sip.telnyx.com) State REPORTING going to sleep
2018-01-11 12:09:27.355470 [DEBUG] switch_core_state_machine.c:610 (sofia/external-kamailio/12013992990@sip.telnyx.com) State Change CS_REPORTING -> CS_DESTROY
2018-01-11 12:09:27.355470 [DEBUG] switch_core_session.c:1665 Session 356 (sofia/external-kamailio/12013992990@sip.telnyx.com) Locked, Waiting on external entities
recv 326 bytes from udp/[10.0.9.54]:5060 at 12:09:28.413832:
------------------------------------------------------------------------
OPTIONS sip:10.0.9.50:12000 SIP/2.0
Via: SIP/2.0/UDP 10.0.9.54;branch=z9hG4bKae87.00980432000000000000000000000000.0
To: <sip:10.0.9.50:12000>
From: <sip:sipcheck@proxy2a-pre.kazoo>;tag=dd842359c3d1f52b828bb146259eb8e4-8608
CSeq: 10 OPTIONS
Call-ID: 60ec4ccf27887dd6-105@10.0.9.54
Max-Forwards: 70