------------------------------------------------------------------------ INVITE sip:1000@159.89.163.195:5020 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.4:64343;branch=z9hG4bK-524287-1---db742d5d8e370f4f;rport Max-Forwards: 70 Contact: To: From: "1000";tag=34407550 Call-ID: 92627MzJlOWE2MzNlZDM5ODhkZTc4YzJjZGM2YmFlZDdhNTU CSeq: 1 INVITE Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS, MESSAGE Content-Type: application/sdp Supported: replaces User-Agent: X-Lite release 5.3.2 stamp 92627 Content-Length: 207 v=0 o=- 13185393934421558 1 IN IP4 192.168.1.4 s=X-Lite release 5.3.2 stamp 92627 c=IN IP4 192.168.1.4 t=0 0 m=audio 50586 RTP/AVP 0 101 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv ------------------------------------------------------------------------ 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.904815 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1000@159.89.163.195:5020 [18923368-a8a9-4a94-9b9f-dcceaca1e6c8] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.904815 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@159.89.163.195:5020) Running State Change CS_NEW (Cur 1 Tot 22) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.904815 [DEBUG] sofia.c:10080 sofia/internal/1000@159.89.163.195:5020 receiving invite from 183.82.203.220:23502 version: 1.8.2 git a98a958 2018-09-26 17:55:25Z 64bit 2018-10-30 12:26:00.904815 [DEBUG] sofia.c:10251 IP 183.82.203.220 Rejected by acl "domains". Falling back to Digest auth. send 907 bytes to udp/[183.82.203.220]:23502 at 12:26:00.915024: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 192.168.1.4:64343;branch=z9hG4bK-524287-1---db742d5d8e370f4f;rport=23502;received=183.82.203.220 From: "1000";tag=34407550 To: ;tag=BUH1eSKQQZ1DN Call-ID: 92627MzJlOWE2MzNlZDM5ODhkZTc4YzJjZGM2YmFlZDdhNTU CSeq: 1 INVITE User-Agent: FreeSWITCH-mod_sofia/1.8.2+git~20180926T175525Z~a98a958ac3~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 Proxy-Authenticate: Digest realm="159.89.163.195", nonce="4dbd93c8-ce87-4255-ade9-f4f291831cbb", algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ 2018-10-30 12:26:00.914806 [DEBUG] sofia.c:2413 detaching session 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.914806 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/1000@159.89.163.195:5020) State NEW recv 349 bytes from udp/[183.82.203.220]:23502 at 12:26:00.942172: ------------------------------------------------------------------------ ACK sip:1000@159.89.163.195:5020 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.4:64343;branch=z9hG4bK-524287-1---db742d5d8e370f4f;rport Max-Forwards: 70 To: ;tag=BUH1eSKQQZ1DN From: "1000";tag=34407550 Call-ID: 92627MzJlOWE2MzNlZDM5ODhkZTc4YzJjZGM2YmFlZDdhNTU CSeq: 1 ACK Content-Length: 0 ------------------------------------------------------------------------ recv 1065 bytes from udp/[183.82.203.220]:23502 at 12:26:00.944902: ------------------------------------------------------------------------ INVITE sip:1000@159.89.163.195:5020 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.4:64343;branch=z9hG4bK-524287-1---2604a17df0500073;rport Max-Forwards: 70 Contact: To: From: "1000";tag=34407550 Call-ID: 92627MzJlOWE2MzNlZDM5ODhkZTc4YzJjZGM2YmFlZDdhNTU CSeq: 2 INVITE Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS, MESSAGE Content-Type: application/sdp Proxy-Authorization: Digest username="1000",realm="159.89.163.195",nonce="4dbd93c8-ce87-4255-ade9-f4f291831cbb",uri="sip:1000@159.89.163.195:5020",response="2a67bbd049f241a35d730f39dc038f80",cnonce="9d2d6facce122e838e69bdec92cc09c4",nc=00000001,qop=auth,algorithm=MD5 Supported: replaces User-Agent: X-Lite release 5.3.2 stamp 92627 Content-Length: 207 v=0 o=- 13185393934421558 1 IN IP4 192.168.1.4 s=X-Lite release 5.3.2 stamp 92627 c=IN IP4 192.168.1.4 t=0 0 m=audio 50586 RTP/AVP 0 101 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv ------------------------------------------------------------------------ 2018-10-30 12:26:00.944817 [DEBUG] sofia.c:2522 Re-attaching to session 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] sofia.c:10080 sofia/internal/1000@159.89.163.195:5020 receiving invite from 183.82.203.220:23502 version: 1.8.2 git a98a958 2018-09-26 17:55:25Z 64bit 2018-10-30 12:26:00.954806 [DEBUG] sofia.c:10251 IP 183.82.203.220 Rejected by acl "domains". Falling back to Digest auth. 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] sofia.c:11388 Setting NAT mode based on nat.auto 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] sofia.c:7291 Channel sofia/internal/1000@159.89.163.195:5020 entering state [received][100] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] sofia.c:7301 Remote SDP: 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 v=0 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 o=- 13185393934421558 1 IN IP4 192.168.1.4 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 s=X-Lite release 5.3.2 stamp 92627 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 c=IN IP4 192.168.1.4 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 t=0 0 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 m=audio 50586 RTP/AVP 0 101 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 a=rtpmap:101 telephone-event/8000 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 a=fmtp:101 0-15 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] sofia.c:7695 (sofia/internal/1000@159.89.163.195:5020) State Change CS_NEW -> CS_INIT 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@159.89.163.195:5020) Running State Change CS_INIT (Cur 1 Tot 22) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@159.89.163.195:5020) State INIT 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] mod_sofia.c:93 sofia/internal/1000@159.89.163.195:5020 SOFIA INIT 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1000@159.89.163.195:5020 Standard INIT 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1000@159.89.163.195:5020) State Change CS_INIT -> CS_ROUTING 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@159.89.163.195:5020) State INIT going to sleep 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@159.89.163.195:5020) Running State Change CS_ROUTING (Cur 1 Tot 22) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] switch_channel.c:2249 (sofia/internal/1000@159.89.163.195:5020) Callstate Change DOWN -> RINGING 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@159.89.163.195:5020) State ROUTING send 402 bytes to udp/[183.82.203.220]:23502 at 12:26:00.956768: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.1.4:64343;branch=z9hG4bK-524287-1---2604a17df0500073;rport=23502;received=183.82.203.220 From: "1000";tag=34407550 To: Call-ID: 92627MzJlOWE2MzNlZDM5ODhkZTc4YzJjZGM2YmFlZDdhNTU CSeq: 2 INVITE User-Agent: FreeSWITCH-mod_sofia/1.8.2+git~20180926T175525Z~a98a958ac3~64bit Content-Length: 0 ------------------------------------------------------------------------ 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] mod_sofia.c:154 sofia/internal/1000@159.89.163.195:5020 SOFIA ROUTING 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] switch_core_state_machine.c:236 sofia/internal/1000@159.89.163.195:5020 Standard ROUTING 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [INFO] mod_dialplan_xml.c:637 Processing 1000 <1000>->1000 in context default 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 parsing [default->ee634e42-e806-4e15-9abe-969d09a3eb33] continue=false 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Regex (PASS) [ee634e42-e806-4e15-9abe-969d09a3eb33] destination_number(1000) =~ /^1000$/ break=on-false 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action clear_digit_action(all) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action export(bind_digit_digit_timeout=200) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action unset(sip_h_X-Weave-DC) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action unset(sip_h_X-Loop-Data) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action unset(sip_h_X-Weave-External) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action unset(sip_h_X-Weave-Internal) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action unset(sip_h_X-Weave-Outbound) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action export(weave_domain=dev-scott) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action export(w_domain=dev-scott.getweave.io) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action export(selected_carrier=twilio) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_log=true) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_direction=inbound) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_dialed_number=8017970178) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_caller_name=Weave ) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_caller_number=7164186158) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_auto_sms_webhook_url=http://admin-api.client:8000/portal/v1/phones/missedcall) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_auto_sms_webhook_key=4G7tEQa0CQB8XlXs-JkdiP3AFRBT3pIrG-hm0k1GK4QZMBzMM4) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action limit(hash dev-scott.getweave.io inbound 10 inbound_exceeded) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(w_cdr_originator=7164186158) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(w_cdr_destination=8017970178) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(w_cdr_direction=inbound) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(w_call_direction=inbound) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(RECORD_STEREO=true) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(media_bug_answer_req=true) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(recording_follow_transfer=true) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(record_post_process_exec_app=bgsystem:curl -d /temp_recordings/dev-scott_2018-10-30_ee634e42-e806-4e15-9abe-969d09a3eb33.mp3 http:///pub?topic=CallRecording) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(execute_on_answer=record_session /temp_recordings/dev-scott_2018-10-30_ee634e42-e806-4e15-9abe-969d09a3eb33.mp3) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action export(location_id=94472cd8-2b1c-4b44-94fe-9708c2bd739d) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(weave_lookup_number=${caller_id_number}) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(continue_on_fail=true) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(hangup_after_bridge=true) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(hold_music=local_stream://moh) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(temp_hold_music=local_stream://moh) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_slug=dev-scott) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(generated_channel_id_eschmidbauer02_dev-scott=1a9b5231-e815-4aba-900d-ecf1089e848f) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_sip_id_eschmidbauer02_dev-scott=44ea632a-a36d-4f3e-b2cc-5272065d1d09) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_sip_name_eschmidbauer02_dev-scott=eschmidbauer02) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(generated_channel_id_eschmidbauer01_dev-scott=8f00162e-9926-4f19-a078-b88487aa6e58) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_sip_id_eschmidbauer01_dev-scott=126385ac-5c42-4b20-bc64-0eec19733a42) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_sip_name_eschmidbauer01_dev-scott=E-VVX400) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(generated_channel_id_xlite_dev-scott=f60035e5-788e-4acd-9d86-18f19ae75dec) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_sip_id_xlite_dev-scott=4073da9c-2359-4f2b-ae75-7fc06748ba78) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_sip_name_xlite_dev-scott=xlite) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(generated_channel_id_eschmidbauer03_dev-scott=f403f20c-cb2e-40f9-bde5-d1ad9e10616b) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_sip_id_eschmidbauer03_dev-scott=1fa6d75e-765e-4110-a8e1-13f7df9275c0) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_sip_name_eschmidbauer03_dev-scott=vvx500) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(generated_channel_id_testline05_dev-scott=3573a9a4-b04e-4ab1-92e8-dfaa401c1b85) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_sip_id_testline05_dev-scott=1b112711-e324-484a-bbc5-f17564d26935) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_sip_name_testline05_dev-scott=testline05) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(mobile_app=eschmidbauer01;xlite) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(desk_phone=eschmidbauer02;eschmidbauer03;testline05) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 Dialplan: sofia/internal/1000@159.89.163.195:5020 Action bridge({origination_uuid=14a8bd6f-af2e-4b1d-8d18-bd59d863387f}user/1003@${domain_name}) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/1000@159.89.163.195:5020) State Change CS_ROUTING -> CS_EXECUTE 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@159.89.163.195:5020) State ROUTING going to sleep 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@159.89.163.195:5020) Running State Change CS_EXECUTE (Cur 1 Tot 22) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1000@159.89.163.195:5020) State EXECUTE 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] mod_sofia.c:209 sofia/internal/1000@159.89.163.195:5020 SOFIA EXECUTE 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] switch_core_state_machine.c:328 sofia/internal/1000@159.89.163.195:5020 Standard EXECUTE 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 clear_digit_action(all) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 export(bind_digit_digit_timeout=200) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [bind_digit_digit_timeout]=[200] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 unset(sip_h_X-Weave-DC) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] mod_dptools.c:1743 UNSET [sip_h_X-Weave-DC] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 unset(sip_h_X-Loop-Data) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] mod_dptools.c:1743 UNSET [sip_h_X-Loop-Data] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 unset(sip_h_X-Weave-External) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] mod_dptools.c:1743 UNSET [sip_h_X-Weave-External] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 unset(sip_h_X-Weave-Internal) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] mod_dptools.c:1743 UNSET [sip_h_X-Weave-Internal] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 unset(sip_h_X-Weave-Outbound) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] mod_dptools.c:1743 UNSET [sip_h_X-Weave-Outbound] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 export(weave_domain=dev-scott) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [weave_domain]=[dev-scott] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 export(w_domain=dev-scott.getweave.io) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [w_domain]=[dev-scott.getweave.io] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 export(selected_carrier=twilio) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [selected_carrier]=[twilio] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_log=true) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_log]=[true] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_direction=inbound) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_direction]=[inbound] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_dialed_number=8017970178) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_dialed_number]=[8017970178] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_caller_name=Weave ) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_caller_name]=[Weave ] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_caller_number=7164186158) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_caller_number]=[7164186158] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_auto_sms_webhook_url=http://admin-api.client:8000/portal/v1/phones/missedcall) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_auto_sms_webhook_url]=[http://admin-api.client:8000/portal/v1/phones/missedcall] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_auto_sms_webhook_key=4G7tEQa0CQB8XlXs-JkdiP3AFRBT3pIrG-hm0k1GK4QZMBzMM4) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_auto_sms_webhook_key]=[4G7tEQa0CQB8XlXs-JkdiP3AFRBT3pIrG-hm0k1GK4QZMBzMM4] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 limit(hash dev-scott.getweave.io inbound 10 inbound_exceeded) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] switch_limit.c:126 incr called: dev-scott.getweave.io_inbound max:10, interval:0 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] mod_hash.c:196 Usage for dev-scott.getweave.io_inbound is now 1/10 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(w_cdr_originator=7164186158) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [w_cdr_originator]=[7164186158] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(w_cdr_destination=8017970178) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [w_cdr_destination]=[8017970178] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(w_cdr_direction=inbound) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [w_cdr_direction]=[inbound] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(w_call_direction=inbound) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [w_call_direction]=[inbound] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(RECORD_STEREO=true) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [RECORD_STEREO]=[true] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(media_bug_answer_req=true) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [media_bug_answer_req]=[true] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(recording_follow_transfer=true) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [recording_follow_transfer]=[true] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(record_post_process_exec_app=bgsystem:curl -d /temp_recordings/dev-scott_2018-10-30_ee634e42-e806-4e15-9abe-969d09a3eb33.mp3 http:///pub?topic=CallRecording) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [record_post_process_exec_app]=[bgsystem:curl -d /temp_recordings/dev-scott_2018-10-30_ee634e42-e806-4e15-9abe-969d09a3eb33.mp3 http:///pub?topic=CallRecording] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(execute_on_answer=record_session /temp_recordings/dev-scott_2018-10-30_ee634e42-e806-4e15-9abe-969d09a3eb33.mp3) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [execute_on_answer]=[record_session /temp_recordings/dev-scott_2018-10-30_ee634e42-e806-4e15-9abe-969d09a3eb33.mp3] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 export(location_id=94472cd8-2b1c-4b44-94fe-9708c2bd739d) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [location_id]=[94472cd8-2b1c-4b44-94fe-9708c2bd739d] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(weave_lookup_number=1000) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [weave_lookup_number]=[1000] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(continue_on_fail=true) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [continue_on_fail]=[true] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(hangup_after_bridge=true) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [hangup_after_bridge]=[true] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(hold_music=local_stream://moh) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.954806 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [hold_music]=[local_stream://moh] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(temp_hold_music=local_stream://moh) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [temp_hold_music]=[local_stream://moh] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_slug=dev-scott) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_slug]=[dev-scott] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(generated_channel_id_eschmidbauer02_dev-scott=1a9b5231-e815-4aba-900d-ecf1089e848f) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [generated_channel_id_eschmidbauer02_dev-scott]=[1a9b5231-e815-4aba-900d-ecf1089e848f] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_sip_id_eschmidbauer02_dev-scott=44ea632a-a36d-4f3e-b2cc-5272065d1d09) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_sip_id_eschmidbauer02_dev-scott]=[44ea632a-a36d-4f3e-b2cc-5272065d1d09] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_sip_name_eschmidbauer02_dev-scott=eschmidbauer02) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_sip_name_eschmidbauer02_dev-scott]=[eschmidbauer02] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(generated_channel_id_eschmidbauer01_dev-scott=8f00162e-9926-4f19-a078-b88487aa6e58) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [generated_channel_id_eschmidbauer01_dev-scott]=[8f00162e-9926-4f19-a078-b88487aa6e58] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_sip_id_eschmidbauer01_dev-scott=126385ac-5c42-4b20-bc64-0eec19733a42) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_sip_id_eschmidbauer01_dev-scott]=[126385ac-5c42-4b20-bc64-0eec19733a42] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_sip_name_eschmidbauer01_dev-scott=E-VVX400) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_sip_name_eschmidbauer01_dev-scott]=[E-VVX400] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(generated_channel_id_xlite_dev-scott=f60035e5-788e-4acd-9d86-18f19ae75dec) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [generated_channel_id_xlite_dev-scott]=[f60035e5-788e-4acd-9d86-18f19ae75dec] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_sip_id_xlite_dev-scott=4073da9c-2359-4f2b-ae75-7fc06748ba78) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_sip_id_xlite_dev-scott]=[4073da9c-2359-4f2b-ae75-7fc06748ba78] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_sip_name_xlite_dev-scott=xlite) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_sip_name_xlite_dev-scott]=[xlite] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(generated_channel_id_eschmidbauer03_dev-scott=f403f20c-cb2e-40f9-bde5-d1ad9e10616b) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [generated_channel_id_eschmidbauer03_dev-scott]=[f403f20c-cb2e-40f9-bde5-d1ad9e10616b] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_sip_id_eschmidbauer03_dev-scott=1fa6d75e-765e-4110-a8e1-13f7df9275c0) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_sip_id_eschmidbauer03_dev-scott]=[1fa6d75e-765e-4110-a8e1-13f7df9275c0] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_sip_name_eschmidbauer03_dev-scott=vvx500) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_sip_name_eschmidbauer03_dev-scott]=[vvx500] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(generated_channel_id_testline05_dev-scott=3573a9a4-b04e-4ab1-92e8-dfaa401c1b85) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [generated_channel_id_testline05_dev-scott]=[3573a9a4-b04e-4ab1-92e8-dfaa401c1b85] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_sip_id_testline05_dev-scott=1b112711-e324-484a-bbc5-f17564d26935) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_sip_id_testline05_dev-scott]=[1b112711-e324-484a-bbc5-f17564d26935] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_sip_name_testline05_dev-scott=testline05) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_sip_name_testline05_dev-scott]=[testline05] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(mobile_app=eschmidbauer01;xlite) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [mobile_app]=[eschmidbauer01;xlite] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 set(desk_phone=eschmidbauer02;eschmidbauer03;testline05) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [desk_phone]=[eschmidbauer02;eschmidbauer03;testline05] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 bridge({origination_uuid=14a8bd6f-af2e-4b1d-8d18-bd59d863387f}user/1003@159.89.163.195) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] switch_channel.c:1250 sofia/internal/1000@159.89.163.195:5020 EXPORTING[export_vars] [bind_digit_digit_timeout]=[200] to event 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] switch_channel.c:1250 sofia/internal/1000@159.89.163.195:5020 EXPORTING[export_vars] [weave_domain]=[dev-scott] to event 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] switch_channel.c:1250 sofia/internal/1000@159.89.163.195:5020 EXPORTING[export_vars] [w_domain]=[dev-scott.getweave.io] to event 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] switch_channel.c:1250 sofia/internal/1000@159.89.163.195:5020 EXPORTING[export_vars] [selected_carrier]=[twilio] to event 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] switch_channel.c:1250 sofia/internal/1000@159.89.163.195:5020 EXPORTING[export_vars] [location_id]=[94472cd8-2b1c-4b44-94fe-9708c2bd739d] to event 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] switch_ivr_originate.c:2204 Parsing global variables 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] switch_channel.c:1250 sofia/internal/1000@159.89.163.195:5020 EXPORTING[export_vars] [bind_digit_digit_timeout]=[200] to event 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] switch_channel.c:1250 sofia/internal/1000@159.89.163.195:5020 EXPORTING[export_vars] [weave_domain]=[dev-scott] to event 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] switch_channel.c:1250 sofia/internal/1000@159.89.163.195:5020 EXPORTING[export_vars] [w_domain]=[dev-scott.getweave.io] to event 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] switch_channel.c:1250 sofia/internal/1000@159.89.163.195:5020 EXPORTING[export_vars] [selected_carrier]=[twilio] to event 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] switch_channel.c:1250 sofia/internal/1000@159.89.163.195:5020 EXPORTING[export_vars] [location_id]=[94472cd8-2b1c-4b44-94fe-9708c2bd739d] to event 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [DEBUG] switch_ivr_originate.c:2204 Parsing global variables 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:00.964805 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1003@183.82.203.220:23585 [14a8bd6f-af2e-4b1d-8d18-bd59d863387f] 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:00.964805 [DEBUG] mod_sofia.c:5028 (sofia/internal/1003@183.82.203.220:23585) State Change CS_NEW -> CS_INIT 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:00.964805 [DEBUG] switch_core_session.c:641 sofia/internal/1003@183.82.203.220:23585 set UUID=14a8bd6f-af2e-4b1d-8d18-bd59d863387f 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:00.964805 [NOTICE] switch_ivr_originate.c:2944 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED] 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:00.964805 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@183.82.203.220:23585) Running State Change CS_INIT (Cur 2 Tot 23) 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:00.964805 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1003@183.82.203.220:23585) State INIT 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:00.964805 [DEBUG] mod_sofia.c:93 sofia/internal/1003@183.82.203.220:23585 SOFIA INIT 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:00.964805 [DEBUG] sofia_glue.c:1299 sofia/internal/1003@183.82.203.220:23585 sending invite version: 1.8.2 git a98a958 2018-09-26 17:55:25Z 64bit 14a8bd6f-af2e-4b1d-8d18-bd59d863387f Local SDP: 14a8bd6f-af2e-4b1d-8d18-bd59d863387f v=0 14a8bd6f-af2e-4b1d-8d18-bd59d863387f o=FreeSWITCH 1540898580 1540898581 IN IP4 159.89.163.195 14a8bd6f-af2e-4b1d-8d18-bd59d863387f s=FreeSWITCH 14a8bd6f-af2e-4b1d-8d18-bd59d863387f c=IN IP4 159.89.163.195 14a8bd6f-af2e-4b1d-8d18-bd59d863387f t=0 0 14a8bd6f-af2e-4b1d-8d18-bd59d863387f m=audio 21780 RTP/AVP 0 101 14a8bd6f-af2e-4b1d-8d18-bd59d863387f a=rtpmap:0 PCMU/8000 14a8bd6f-af2e-4b1d-8d18-bd59d863387f a=rtpmap:101 telephone-event/8000 14a8bd6f-af2e-4b1d-8d18-bd59d863387f a=fmtp:101 0-16 14a8bd6f-af2e-4b1d-8d18-bd59d863387f a=ptime:20 14a8bd6f-af2e-4b1d-8d18-bd59d863387f a=sendrecv 14a8bd6f-af2e-4b1d-8d18-bd59d863387f send 1287 bytes to tcp/[183.82.203.220]:23585 at 12:26:00.972819: ------------------------------------------------------------------------ INVITE sip:1003@183.82.203.220:23585;transport=TCP;rinstance=eff915fadb99c0b0 SIP/2.0 Via: SIP/2.0/TCP 159.89.163.195:5020;branch=z9hG4bKt59Q4U8B1X7BD Max-Forwards: 69 From: "Extension 1000" ;tag=DD4jjFNyHHeKc To: Call-ID: b64d71ce-570b-1237-2b97-528373432f88 CSeq: 130124116 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.8.2+git~20180926T175525Z~a98a958ac3~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: 224 X-FS-Support: update_display,send_info Remote-Party-ID: "Extension 1000" ;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 1540898580 1540898581 IN IP4 159.89.163.195 s=FreeSWITCH c=IN IP4 159.89.163.195 t=0 0 m=audio 21780 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:00.964805 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1003@183.82.203.220:23585 Standard INIT 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:00.964805 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1003@183.82.203.220:23585) State Change CS_INIT -> CS_ROUTING 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:00.964805 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1003@183.82.203.220:23585) State INIT going to sleep 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:00.964805 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@183.82.203.220:23585) Running State Change CS_ROUTING (Cur 2 Tot 23) 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:00.964805 [DEBUG] sofia.c:7291 Channel sofia/internal/1003@183.82.203.220:23585 entering state [calling][0] 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:00.964805 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1003@183.82.203.220:23585) State ROUTING 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:00.964805 [DEBUG] mod_sofia.c:154 sofia/internal/1003@183.82.203.220:23585 SOFIA ROUTING 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:00.964805 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1003@183.82.203.220:23585) State Change CS_ROUTING -> CS_CONSUME_MEDIA 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:00.964805 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1003@183.82.203.220:23585) State ROUTING going to sleep 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:00.964805 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@183.82.203.220:23585) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 23) 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:00.964805 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1003@183.82.203.220:23585) State CONSUME_MEDIA 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:00.964805 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1003@183.82.203.220:23585) State CONSUME_MEDIA going to sleep recv 324 bytes from tcp/[183.82.203.220]:23585 at 12:26:01.700022: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/TCP 159.89.163.195:5020;branch=z9hG4bKt59Q4U8B1X7BD To: From: "Extension 1000" ;tag=DD4jjFNyHHeKc Call-ID: b64d71ce-570b-1237-2b97-528373432f88 CSeq: 130124116 INVITE Content-Length: 0 ------------------------------------------------------------------------ recv 529 bytes from tcp/[183.82.203.220]:23585 at 12:26:02.510275: ------------------------------------------------------------------------ SIP/2.0 180 Ringing Via: SIP/2.0/TCP 159.89.163.195:5020;branch=z9hG4bKt59Q4U8B1X7BD Contact: To: ;tag=fc90b801 From: "Extension 1000" ;tag=DD4jjFNyHHeKc Call-ID: b64d71ce-570b-1237-2b97-528373432f88 CSeq: 130124116 INVITE Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE User-Agent: Zoiper rv2.8.109 Allow-Events: presence, kpml, talk Content-Length: 0 ------------------------------------------------------------------------ 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:02.504822 [DEBUG] sofia.c:7291 Channel sofia/internal/1003@183.82.203.220:23585 entering state [proceeding][180] 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:02.504822 [NOTICE] sofia.c:7401 Ring-Ready sofia/internal/1003@183.82.203.220:23585! 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:02.504822 [DEBUG] switch_channel.c:3354 (sofia/internal/1003@183.82.203.220:23585) Callstate Change DOWN -> RINGING send 903 bytes to udp/[183.82.203.220]:23502 at 12:26:02.518341: ------------------------------------------------------------------------ SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.1.4:64343;branch=z9hG4bK-524287-1---2604a17df0500073;rport=23502;received=183.82.203.220 From: "1000";tag=34407550 To: ;tag=c4atgm4tm8Q0g Call-ID: 92627MzJlOWE2MzNlZDM5ODhkZTc4YzJjZGM2YmFlZDdhNTU CSeq: 2 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.8.2+git~20180926T175525Z~a98a958ac3~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: "1000" ;party=calling;privacy=off;screen=no ------------------------------------------------------------------------ 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:02.514811 [NOTICE] mod_sofia.c:2419 Ring-Ready sofia/internal/1000@159.89.163.195:5020! 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:02.514811 [DEBUG] sofia.c:7291 Channel sofia/internal/1000@159.89.163.195:5020 entering state [early][180] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:02.514811 [NOTICE] switch_ivr_originate.c:553 Ring Ready sofia/internal/1000@159.89.163.195:5020! recv 802 bytes from tcp/[183.82.203.220]:23585 at 12:26:05.406842: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TCP 159.89.163.195:5020;branch=z9hG4bKt59Q4U8B1X7BD Contact: To: ;tag=fc90b801 From: "Extension 1000" ;tag=DD4jjFNyHHeKc Call-ID: b64d71ce-570b-1237-2b97-528373432f88 CSeq: 130124116 INVITE Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE Content-Type: application/sdp User-Agent: Zoiper rv2.8.109 Allow-Events: presence, kpml, talk Content-Length: 245 v=0 o=Zoiper 0 2 IN IP4 183.82.203.220 s=Zoiper c=IN IP4 183.82.203.220 t=0 0 m=audio 24103 RTP/AVP 0 3 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=sendrecv ------------------------------------------------------------------------ 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:05.404815 [DEBUG] sofia.c:7291 Channel sofia/internal/1003@183.82.203.220:23585 entering state [completing][200] 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:05.404815 [DEBUG] sofia.c:7301 Remote SDP: 14a8bd6f-af2e-4b1d-8d18-bd59d863387f v=0 14a8bd6f-af2e-4b1d-8d18-bd59d863387f o=Zoiper 0 2 IN IP4 183.82.203.220 14a8bd6f-af2e-4b1d-8d18-bd59d863387f s=Zoiper 14a8bd6f-af2e-4b1d-8d18-bd59d863387f c=IN IP4 183.82.203.220 14a8bd6f-af2e-4b1d-8d18-bd59d863387f t=0 0 14a8bd6f-af2e-4b1d-8d18-bd59d863387f m=audio 24103 RTP/AVP 0 3 8 101 14a8bd6f-af2e-4b1d-8d18-bd59d863387f a=rtpmap:0 PCMU/8000 14a8bd6f-af2e-4b1d-8d18-bd59d863387f a=rtpmap:3 GSM/8000 14a8bd6f-af2e-4b1d-8d18-bd59d863387f a=rtpmap:8 PCMA/8000 14a8bd6f-af2e-4b1d-8d18-bd59d863387f a=rtpmap:101 telephone-event/8000 14a8bd6f-af2e-4b1d-8d18-bd59d863387f a=fmtp:101 0-16 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:05.404815 [NOTICE] sofia.c:7304 Pre-Answer sofia/internal/1003@183.82.203.220:23585! 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:05.404815 [DEBUG] switch_channel.c:3482 (sofia/internal/1003@183.82.203.220:23585) Callstate Change RINGING -> EARLY send 441 bytes to udp/[183.82.203.220]:23581 at 12:26:05.408882: ------------------------------------------------------------------------ ACK sip:1003@183.82.203.220:23581 SIP/2.0 Via: SIP/2.0/UDP 159.89.163.195:5020;rport;branch=z9hG4bKUe3g6pSFy6Xyr Max-Forwards: 70 From: "Extension 1000" ;tag=DD4jjFNyHHeKc To: ;tag=fc90b801 Call-ID: b64d71ce-570b-1237-2b97-528373432f88 CSeq: 130124116 ACK Contact: Content-Length: 0 ------------------------------------------------------------------------ 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:05.404815 [DEBUG] sofia.c:7291 Channel sofia/internal/1003@183.82.203.220:23585 entering state [ready][200] 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:05.404815 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:05.404815 [DEBUG] switch_core_media.c:5533 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:05.404815 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1] 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:05.404815 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:05.404815 [DEBUG] switch_core_media.c:5394 Set telephone-event payload to 101@8000 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:05.404815 [DEBUG] switch_core_media.c:3781 Set Codec sofia/internal/1003@183.82.203.220:23585 PCMU/8000 20 ms 160 samples 64000 bits 1 channels 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:05.404815 [DEBUG] switch_core_codec.c:111 sofia/internal/1003@183.82.203.220:23585 Original read codec set to PCMU:0 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:05.404815 [DEBUG] switch_core_media.c:5737 Set telephone-event payload to 101@8000 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:05.404815 [DEBUG] switch_core_media.c:5795 sofia/internal/1003@183.82.203.220:23585 Set 2833 dtmf send payload to 101 recv payload to 101 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:05.404815 [DEBUG] switch_core_media.c:8511 AUDIO RTP [sofia/internal/1003@183.82.203.220:23585] 159.89.163.195 port 21780 -> 183.82.203.220 port 24103 codec: 0 ms: 20 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.404815 [INFO] switch_ivr_originate.c:3747 Sending early media 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.404815 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.404815 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.404815 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.404815 [DEBUG] switch_core_media.c:5533 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.404815 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.404815 [DEBUG] switch_core_media.c:5394 Set telephone-event payload to 101@8000 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.404815 [DEBUG] switch_core_media.c:3781 Set Codec sofia/internal/1000@159.89.163.195:5020 PCMU/8000 20 ms 160 samples 64000 bits 1 channels 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.404815 [DEBUG] switch_core_codec.c:111 sofia/internal/1000@159.89.163.195:5020 Original read codec set to PCMU:0 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.404815 [DEBUG] switch_core_media.c:5737 Set telephone-event payload to 101@8000 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.404815 [DEBUG] switch_core_media.c:5795 sofia/internal/1000@159.89.163.195:5020 Set 2833 dtmf send payload to 101 recv payload to 101 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.404815 [DEBUG] switch_core_media.c:8511 AUDIO RTP [sofia/internal/1000@159.89.163.195:5020] 159.89.163.195 port 18476 -> 192.168.1.4 port 50586 codec: 0 ms: 20 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:05.404815 [DEBUG] switch_rtp.c:4300 Starting timer [soft] 160 bytes per 20ms 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.404815 [DEBUG] switch_rtp.c:4300 Starting timer [soft] 160 bytes per 20ms 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:05.404815 [DEBUG] switch_core_media.c:8815 sofia/internal/1003@183.82.203.220:23585 Set 2833 dtmf send payload to 101 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:05.404815 [DEBUG] switch_core_media.c:8822 sofia/internal/1003@183.82.203.220:23585 Set 2833 dtmf receive payload to 101 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:05.404815 [DEBUG] switch_core_media.c:8845 sofia/internal/1003@183.82.203.220:23585 Set rtp dtmf delay to 40 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:05.404815 [NOTICE] sofia.c:8429 Channel [sofia/internal/1003@183.82.203.220:23585] has been answered 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:05.404815 [DEBUG] switch_channel.c:3781 (sofia/internal/1003@183.82.203.220:23585) Callstate Change EARLY -> ACTIVE 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.404815 [DEBUG] switch_core_media.c:8815 sofia/internal/1000@159.89.163.195:5020 Set 2833 dtmf send payload to 101 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.404815 [DEBUG] switch_core_media.c:8822 sofia/internal/1000@159.89.163.195:5020 Set 2833 dtmf receive payload to 101 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.404815 [DEBUG] switch_core_media.c:8845 sofia/internal/1000@159.89.163.195:5020 Set rtp dtmf delay to 40 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.404815 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/1000@159.89.163.195:5020! 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.404815 [DEBUG] switch_channel.c:3482 (sofia/internal/1000@159.89.163.195:5020) Callstate Change RINGING -> EARLY 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.404815 [DEBUG] switch_core_media.c:8494 Audio params are unchanged for sofia/internal/1000@159.89.163.195:5020. 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.404815 [DEBUG] mod_sofia.c:2514 Ring SDP: 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 v=0 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 o=FreeSWITCH 1540901889 1540901890 IN IP4 159.89.163.195 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 s=FreeSWITCH 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 c=IN IP4 159.89.163.195 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 t=0 0 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 m=audio 18476 RTP/AVP 0 101 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 a=rtpmap:0 PCMU/8000 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 a=rtpmap:101 telephone-event/8000 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 a=fmtp:101 0-16 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 a=ptime:20 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 a=sendrecv 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 send 1183 bytes to udp/[183.82.203.220]:23502 at 12:26:05.414734: ------------------------------------------------------------------------ SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 192.168.1.4:64343;branch=z9hG4bK-524287-1---2604a17df0500073;rport=23502;received=183.82.203.220 From: "1000";tag=34407550 To: ;tag=c4atgm4tm8Q0g Call-ID: 92627MzJlOWE2MzNlZDM5ODhkZTc4YzJjZGM2YmFlZDdhNTU CSeq: 2 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.8.2+git~20180926T175525Z~a98a958ac3~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: 224 Remote-Party-ID: "Outbound Call" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1540901889 1540901890 IN IP4 159.89.163.195 s=FreeSWITCH c=IN IP4 159.89.163.195 t=0 0 m=audio 18476 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.414826 [DEBUG] sofia.c:7291 Channel sofia/internal/1000@159.89.163.195:5020 entering state [early][183] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.414826 [DEBUG] switch_ivr_originate.c:3798 Originate Resulted in Success: [sofia/internal/1003@183.82.203.220:23585] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.414826 [DEBUG] switch_core_media.c:8494 Audio params are unchanged for sofia/internal/1000@159.89.163.195:5020. 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.414826 [DEBUG] mod_sofia.c:881 Local SDP sofia/internal/1000@159.89.163.195:5020: 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 v=0 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 o=FreeSWITCH 1540901889 1540901891 IN IP4 159.89.163.195 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 s=FreeSWITCH 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 c=IN IP4 159.89.163.195 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 t=0 0 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 m=audio 18476 RTP/AVP 0 101 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 a=rtpmap:0 PCMU/8000 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 a=rtpmap:101 telephone-event/8000 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 a=fmtp:101 0-16 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 a=ptime:20 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 a=sendrecv 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 send 1205 bytes to udp/[183.82.203.220]:23502 at 12:26:05.416480: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.4:64343;branch=z9hG4bK-524287-1---2604a17df0500073;rport=23502;received=183.82.203.220 From: "1000";tag=34407550 To: ;tag=c4atgm4tm8Q0g Call-ID: 92627MzJlOWE2MzNlZDM5ODhkZTc4YzJjZGM2YmFlZDdhNTU CSeq: 2 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.8.2+git~20180926T175525Z~a98a958ac3~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 Session-Expires: 120;refresher=uas Content-Type: application/sdp Content-Disposition: session Content-Length: 224 Remote-Party-ID: "Outbound Call" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1540901889 1540901890 IN IP4 159.89.163.195 s=FreeSWITCH c=IN IP4 159.89.163.195 t=0 0 m=audio 18476 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.414826 [DEBUG] sofia.c:7291 Channel sofia/internal/1000@159.89.163.195:5020 entering state [completed][200] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.414826 [NOTICE] switch_ivr_originate.c:3740 Channel [sofia/internal/1000@159.89.163.195:5020] has been answered 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 EXECUTE sofia/internal/1000@159.89.163.195:5020 record_session(/temp_recordings/dev-scott_2018-10-30_ee634e42-e806-4e15-9abe-969d09a3eb33.mp3) 2018-10-30 12:26:05.414826 [ERR] switch_core_file.c:301 Invalid file format [mp3] for [/temp_recordings/dev-scott_2018-10-30_ee634e42-e806-4e15-9abe-969d09a3eb33.mp3]! 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.414826 [ERR] switch_ivr_async.c:2737 Error opening /temp_recordings/dev-scott_2018-10-30_ee634e42-e806-4e15-9abe-969d09a3eb33.mp3 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.414826 [DEBUG] switch_channel.c:3781 (sofia/internal/1000@159.89.163.195:5020) Callstate Change EARLY -> ACTIVE 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.414826 [DEBUG] switch_ivr_originate.c:3798 Originate Resulted in Success: [sofia/internal/1003@183.82.203.220:23585] 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:05.414826 [DEBUG] switch_ivr_bridge.c:1782 (sofia/internal/1003@183.82.203.220:23585) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:05.414826 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@183.82.203.220:23585) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 23) 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:05.414826 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/1003@183.82.203.220:23585) State EXCHANGE_MEDIA 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:05.414826 [DEBUG] mod_sofia.c:645 SOFIA EXCHANGE_MEDIA recv 478 bytes from udp/[183.82.203.220]:23502 at 12:26:05.546249: ------------------------------------------------------------------------ ACK sip:1000@159.89.163.195:5020;transport=udp SIP/2.0 Via: SIP/2.0/UDP 192.168.1.4:64343;branch=z9hG4bK-524287-1---0fd46e1c2958b736;rport Max-Forwards: 70 Contact: To: ;tag=c4atgm4tm8Q0g From: "1000";tag=34407550 Call-ID: 92627MzJlOWE2MzNlZDM5ODhkZTc4YzJjZGM2YmFlZDdhNTU CSeq: 2 ACK User-Agent: X-Lite release 5.3.2 stamp 92627 Content-Length: 0 ------------------------------------------------------------------------ 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.544816 [DEBUG] sofia.c:7291 Channel sofia/internal/1000@159.89.163.195:5020 entering state [ready][200] 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:05.724831 [DEBUG] switch_rtp.c:7550 Correct audio ip/port confirmed. 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:05.764813 [INFO] switch_rtp.c:7510 Auto Changing audio port from 192.168.1.4:50586 to 183.82.203.220:24108 recv 802 bytes from tcp/[183.82.203.220]:23585 at 12:26:05.904223: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TCP 159.89.163.195:5020;branch=z9hG4bKt59Q4U8B1X7BD Contact: To: ;tag=fc90b801 From: "Extension 1000" ;tag=DD4jjFNyHHeKc Call-ID: b64d71ce-570b-1237-2b97-528373432f88 CSeq: 130124116 INVITE Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE Content-Type: application/sdp User-Agent: Zoiper rv2.8.109 Allow-Events: presence, kpml, talk Content-Length: 245 v=0 o=Zoiper 0 2 IN IP4 183.82.203.220 s=Zoiper c=IN IP4 183.82.203.220 t=0 0 m=audio 24103 RTP/AVP 0 3 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=sendrecv ------------------------------------------------------------------------ send 441 bytes to udp/[183.82.203.220]:23581 at 12:26:05.904343: ------------------------------------------------------------------------ ACK sip:1003@183.82.203.220:23581 SIP/2.0 Via: SIP/2.0/UDP 159.89.163.195:5020;rport;branch=z9hG4bKUe3g6pSFy6Xyr Max-Forwards: 70 From: "Extension 1000" ;tag=DD4jjFNyHHeKc To: ;tag=fc90b801 Call-ID: b64d71ce-570b-1237-2b97-528373432f88 CSeq: 130124116 ACK Contact: Content-Length: 0 ------------------------------------------------------------------------ recv 802 bytes from tcp/[183.82.203.220]:23585 at 12:26:06.903636: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TCP 159.89.163.195:5020;branch=z9hG4bKt59Q4U8B1X7BD Contact: To: ;tag=fc90b801 From: "Extension 1000" ;tag=DD4jjFNyHHeKc Call-ID: b64d71ce-570b-1237-2b97-528373432f88 CSeq: 130124116 INVITE Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE Content-Type: application/sdp User-Agent: Zoiper rv2.8.109 Allow-Events: presence, kpml, talk Content-Length: 245 v=0 o=Zoiper 0 2 IN IP4 183.82.203.220 s=Zoiper c=IN IP4 183.82.203.220 t=0 0 m=audio 24103 RTP/AVP 0 3 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=sendrecv ------------------------------------------------------------------------ send 441 bytes to udp/[183.82.203.220]:23581 at 12:26:06.903794: ------------------------------------------------------------------------ ACK sip:1003@183.82.203.220:23581 SIP/2.0 Via: SIP/2.0/UDP 159.89.163.195:5020;rport;branch=z9hG4bKUe3g6pSFy6Xyr Max-Forwards: 70 From: "Extension 1000" ;tag=DD4jjFNyHHeKc To: ;tag=fc90b801 Call-ID: b64d71ce-570b-1237-2b97-528373432f88 CSeq: 130124116 ACK Contact: Content-Length: 0 ------------------------------------------------------------------------ recv 802 bytes from tcp/[183.82.203.220]:23585 at 12:26:08.903960: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TCP 159.89.163.195:5020;branch=z9hG4bKt59Q4U8B1X7BD Contact: To: ;tag=fc90b801 From: "Extension 1000" ;tag=DD4jjFNyHHeKc Call-ID: b64d71ce-570b-1237-2b97-528373432f88 CSeq: 130124116 INVITE Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE Content-Type: application/sdp User-Agent: Zoiper rv2.8.109 Allow-Events: presence, kpml, talk Content-Length: 245 v=0 o=Zoiper 0 2 IN IP4 183.82.203.220 s=Zoiper c=IN IP4 183.82.203.220 t=0 0 m=audio 24103 RTP/AVP 0 3 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=sendrecv ------------------------------------------------------------------------ send 441 bytes to udp/[183.82.203.220]:23581 at 12:26:08.904084: ------------------------------------------------------------------------ ACK sip:1003@183.82.203.220:23581 SIP/2.0 Via: SIP/2.0/UDP 159.89.163.195:5020;rport;branch=z9hG4bKUe3g6pSFy6Xyr Max-Forwards: 70 From: "Extension 1000" ;tag=DD4jjFNyHHeKc To: ;tag=fc90b801 Call-ID: b64d71ce-570b-1237-2b97-528373432f88 CSeq: 130124116 ACK Contact: Content-Length: 0 ------------------------------------------------------------------------ recv 802 bytes from tcp/[183.82.203.220]:23585 at 12:26:12.904473: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TCP 159.89.163.195:5020;branch=z9hG4bKt59Q4U8B1X7BD Contact: To: ;tag=fc90b801 From: "Extension 1000" ;tag=DD4jjFNyHHeKc Call-ID: b64d71ce-570b-1237-2b97-528373432f88 CSeq: 130124116 INVITE Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE Content-Type: application/sdp User-Agent: Zoiper rv2.8.109 Allow-Events: presence, kpml, talk Content-Length: 245 v=0 o=Zoiper 0 2 IN IP4 183.82.203.220 s=Zoiper c=IN IP4 183.82.203.220 t=0 0 m=audio 24103 RTP/AVP 0 3 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=sendrecv ------------------------------------------------------------------------ send 441 bytes to udp/[183.82.203.220]:23581 at 12:26:12.904623: ------------------------------------------------------------------------ ACK sip:1003@183.82.203.220:23581 SIP/2.0 Via: SIP/2.0/UDP 159.89.163.195:5020;rport;branch=z9hG4bKUe3g6pSFy6Xyr Max-Forwards: 70 From: "Extension 1000" ;tag=DD4jjFNyHHeKc To: ;tag=fc90b801 Call-ID: b64d71ce-570b-1237-2b97-528373432f88 CSeq: 130124116 ACK Contact: Content-Length: 0 ------------------------------------------------------------------------ recv 802 bytes from tcp/[183.82.203.220]:23585 at 12:26:16.905169: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TCP 159.89.163.195:5020;branch=z9hG4bKt59Q4U8B1X7BD Contact: To: ;tag=fc90b801 From: "Extension 1000" ;tag=DD4jjFNyHHeKc Call-ID: b64d71ce-570b-1237-2b97-528373432f88 CSeq: 130124116 INVITE Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE Content-Type: application/sdp User-Agent: Zoiper rv2.8.109 Allow-Events: presence, kpml, talk Content-Length: 245 v=0 o=Zoiper 0 2 IN IP4 183.82.203.220 s=Zoiper c=IN IP4 183.82.203.220 t=0 0 m=audio 24103 RTP/AVP 0 3 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=sendrecv ------------------------------------------------------------------------ send 441 bytes to udp/[183.82.203.220]:23581 at 12:26:16.905299: ------------------------------------------------------------------------ ACK sip:1003@183.82.203.220:23581 SIP/2.0 Via: SIP/2.0/UDP 159.89.163.195:5020;rport;branch=z9hG4bKUe3g6pSFy6Xyr Max-Forwards: 70 From: "Extension 1000" ;tag=DD4jjFNyHHeKc To: ;tag=fc90b801 Call-ID: b64d71ce-570b-1237-2b97-528373432f88 CSeq: 130124116 ACK Contact: Content-Length: 0 ------------------------------------------------------------------------ recv 802 bytes from tcp/[183.82.203.220]:23585 at 12:26:20.905699: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TCP 159.89.163.195:5020;branch=z9hG4bKt59Q4U8B1X7BD Contact: To: ;tag=fc90b801 From: "Extension 1000" ;tag=DD4jjFNyHHeKc Call-ID: b64d71ce-570b-1237-2b97-528373432f88 CSeq: 130124116 INVITE Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE Content-Type: application/sdp User-Agent: Zoiper rv2.8.109 Allow-Events: presence, kpml, talk Content-Length: 245 v=0 o=Zoiper 0 2 IN IP4 183.82.203.220 s=Zoiper c=IN IP4 183.82.203.220 t=0 0 m=audio 24103 RTP/AVP 0 3 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=sendrecv ------------------------------------------------------------------------ send 441 bytes to udp/[183.82.203.220]:23581 at 12:26:20.905827: ------------------------------------------------------------------------ ACK sip:1003@183.82.203.220:23581 SIP/2.0 Via: SIP/2.0/UDP 159.89.163.195:5020;rport;branch=z9hG4bKUe3g6pSFy6Xyr Max-Forwards: 70 From: "Extension 1000" ;tag=DD4jjFNyHHeKc To: ;tag=fc90b801 Call-ID: b64d71ce-570b-1237-2b97-528373432f88 CSeq: 130124116 ACK Contact: Content-Length: 0 ------------------------------------------------------------------------ recv 802 bytes from tcp/[183.82.203.220]:23585 at 12:26:24.906082: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TCP 159.89.163.195:5020;branch=z9hG4bKt59Q4U8B1X7BD Contact: To: ;tag=fc90b801 From: "Extension 1000" ;tag=DD4jjFNyHHeKc Call-ID: b64d71ce-570b-1237-2b97-528373432f88 CSeq: 130124116 INVITE Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE Content-Type: application/sdp User-Agent: Zoiper rv2.8.109 Allow-Events: presence, kpml, talk Content-Length: 245 v=0 o=Zoiper 0 2 IN IP4 183.82.203.220 s=Zoiper c=IN IP4 183.82.203.220 t=0 0 m=audio 24103 RTP/AVP 0 3 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=sendrecv ------------------------------------------------------------------------ send 441 bytes to udp/[183.82.203.220]:23581 at 12:26:24.906202: ------------------------------------------------------------------------ ACK sip:1003@183.82.203.220:23581 SIP/2.0 Via: SIP/2.0/UDP 159.89.163.195:5020;rport;branch=z9hG4bKUe3g6pSFy6Xyr Max-Forwards: 70 From: "Extension 1000" ;tag=DD4jjFNyHHeKc To: ;tag=fc90b801 Call-ID: b64d71ce-570b-1237-2b97-528373432f88 CSeq: 130124116 ACK Contact: Content-Length: 0 ------------------------------------------------------------------------ recv 802 bytes from tcp/[183.82.203.220]:23585 at 12:26:28.907575: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TCP 159.89.163.195:5020;branch=z9hG4bKt59Q4U8B1X7BD Contact: To: ;tag=fc90b801 From: "Extension 1000" ;tag=DD4jjFNyHHeKc Call-ID: b64d71ce-570b-1237-2b97-528373432f88 CSeq: 130124116 INVITE Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE Content-Type: application/sdp User-Agent: Zoiper rv2.8.109 Allow-Events: presence, kpml, talk Content-Length: 245 v=0 o=Zoiper 0 2 IN IP4 183.82.203.220 s=Zoiper c=IN IP4 183.82.203.220 t=0 0 m=audio 24103 RTP/AVP 0 3 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=sendrecv ------------------------------------------------------------------------ send 441 bytes to udp/[183.82.203.220]:23581 at 12:26:28.907695: ------------------------------------------------------------------------ ACK sip:1003@183.82.203.220:23581 SIP/2.0 Via: SIP/2.0/UDP 159.89.163.195:5020;rport;branch=z9hG4bKUe3g6pSFy6Xyr Max-Forwards: 70 From: "Extension 1000" ;tag=DD4jjFNyHHeKc To: ;tag=fc90b801 Call-ID: b64d71ce-570b-1237-2b97-528373432f88 CSeq: 130124116 ACK Contact: Content-Length: 0 ------------------------------------------------------------------------ recv 802 bytes from tcp/[183.82.203.220]:23585 at 12:26:32.910912: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TCP 159.89.163.195:5020;branch=z9hG4bKt59Q4U8B1X7BD Contact: To: ;tag=fc90b801 From: "Extension 1000" ;tag=DD4jjFNyHHeKc Call-ID: b64d71ce-570b-1237-2b97-528373432f88 CSeq: 130124116 INVITE Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE Content-Type: application/sdp User-Agent: Zoiper rv2.8.109 Allow-Events: presence, kpml, talk Content-Length: 245 v=0 o=Zoiper 0 2 IN IP4 183.82.203.220 s=Zoiper c=IN IP4 183.82.203.220 t=0 0 m=audio 24103 RTP/AVP 0 3 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=sendrecv ------------------------------------------------------------------------ send 441 bytes to udp/[183.82.203.220]:23581 at 12:26:32.911024: ------------------------------------------------------------------------ ACK sip:1003@183.82.203.220:23581 SIP/2.0 Via: SIP/2.0/UDP 159.89.163.195:5020;rport;branch=z9hG4bKUe3g6pSFy6Xyr Max-Forwards: 70 From: "Extension 1000" ;tag=DD4jjFNyHHeKc To: ;tag=fc90b801 Call-ID: b64d71ce-570b-1237-2b97-528373432f88 CSeq: 130124116 ACK Contact: Content-Length: 0 ------------------------------------------------------------------------ recv 802 bytes from tcp/[183.82.203.220]:23585 at 12:26:36.909961: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TCP 159.89.163.195:5020;branch=z9hG4bKt59Q4U8B1X7BD Contact: To: ;tag=fc90b801 From: "Extension 1000" ;tag=DD4jjFNyHHeKc Call-ID: b64d71ce-570b-1237-2b97-528373432f88 CSeq: 130124116 INVITE Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE Content-Type: application/sdp User-Agent: Zoiper rv2.8.109 Allow-Events: presence, kpml, talk Content-Length: 245 v=0 o=Zoiper 0 2 IN IP4 183.82.203.220 s=Zoiper c=IN IP4 183.82.203.220 t=0 0 m=audio 24103 RTP/AVP 0 3 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=sendrecv ------------------------------------------------------------------------ send 441 bytes to udp/[183.82.203.220]:23581 at 12:26:36.910067: ------------------------------------------------------------------------ ACK sip:1003@183.82.203.220:23581 SIP/2.0 Via: SIP/2.0/UDP 159.89.163.195:5020;rport;branch=z9hG4bKUe3g6pSFy6Xyr Max-Forwards: 70 From: "Extension 1000" ;tag=DD4jjFNyHHeKc To: ;tag=fc90b801 Call-ID: b64d71ce-570b-1237-2b97-528373432f88 CSeq: 130124116 ACK Contact: Content-Length: 0 ------------------------------------------------------------------------ recv 479 bytes from tcp/[183.82.203.220]:23585 at 12:26:37.403601: ------------------------------------------------------------------------ BYE sip:mod_sofia@159.89.163.195:5020;transport=tcp SIP/2.0 Via: SIP/2.0/TCP 183.82.203.220:23585;branch=z9hG4bK-524287-1---2f6d96be77c073e1;rport Max-Forwards: 70 Contact: To: "Extension 1000" ;tag=DD4jjFNyHHeKc From: ;tag=fc90b801 Call-ID: b64d71ce-570b-1237-2b97-528373432f88 CSeq: 2 BYE User-Agent: Zoiper rv2.8.109 Content-Length: 0 ------------------------------------------------------------------------ 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:37.404822 [NOTICE] sofia.c:1079 Hangup sofia/internal/1003@183.82.203.220:23585 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] send 572 bytes to tcp/[183.82.203.220]:23585 at 12:26:37.410884: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TCP 183.82.203.220:23585;branch=z9hG4bK-524287-1---2f6d96be77c073e1;rport=23585 From: ;tag=fc90b801 To: "Extension 1000" ;tag=DD4jjFNyHHeKc Call-ID: b64d71ce-570b-1237-2b97-528373432f88 CSeq: 2 BYE User-Agent: FreeSWITCH-mod_sofia/1.8.2+git~20180926T175525Z~a98a958ac3~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Content-Length: 0 ------------------------------------------------------------------------ 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:37.404822 [DEBUG] switch_ivr_bridge.c:917 BRIDGE THREAD DONE [sofia/internal/1003@183.82.203.220:23585] 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:37.404822 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/1003@183.82.203.220:23585) State EXCHANGE_MEDIA going to sleep 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:37.404822 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@183.82.203.220:23585) Running State Change CS_HANGUP (Cur 2 Tot 23) 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:37.404822 [DEBUG] switch_core_state_machine.c:847 (sofia/internal/1003@183.82.203.220:23585) Callstate Change ACTIVE -> HANGUP 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:37.404822 [DEBUG] switch_core_state_machine.c:849 (sofia/internal/1003@183.82.203.220:23585) State HANGUP 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:37.404822 [DEBUG] mod_sofia.c:449 Channel sofia/internal/1003@183.82.203.220:23585 hanging up, cause: NORMAL_CLEARING 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:37.404822 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1003@183.82.203.220:23585 Standard HANGUP, cause: NORMAL_CLEARING 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:37.404822 [DEBUG] switch_core_state_machine.c:849 (sofia/internal/1003@183.82.203.220:23585) State HANGUP going to sleep 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:37.404822 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1003@183.82.203.220:23585) State Change CS_HANGUP -> CS_REPORTING 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:37.404822 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@183.82.203.220:23585) Running State Change CS_REPORTING (Cur 2 Tot 23) 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:37.404822 [DEBUG] switch_core_state_machine.c:935 (sofia/internal/1003@183.82.203.220:23585) State REPORTING 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:37.404822 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1003@183.82.203.220:23585 Standard REPORTING, cause: NORMAL_CLEARING 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:37.404822 [DEBUG] switch_core_state_machine.c:935 (sofia/internal/1003@183.82.203.220:23585) State REPORTING going to sleep 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:37.414836 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1003@183.82.203.220:23585) State Change CS_REPORTING -> CS_DESTROY 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:37.414836 [DEBUG] switch_core_session.c:1714 Session 23 (sofia/internal/1003@183.82.203.220:23585) Locked, Waiting on external entities 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:37.414836 [DEBUG] switch_ivr_bridge.c:825 sofia/internal/1003@183.82.203.220:23585 ending bridge by request from write function 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:37.414836 [DEBUG] switch_ivr_bridge.c:917 BRIDGE THREAD DONE [sofia/internal/1000@159.89.163.195:5020] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:37.414836 [NOTICE] switch_ivr_bridge.c:1933 Hangup sofia/internal/1000@159.89.163.195:5020 [CS_EXECUTE] [NORMAL_CLEARING] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:37.414836 [DEBUG] mod_hash.c:297 Usage for dev-scott.getweave.io_inbound is now 0 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:37.414836 [DEBUG] switch_core_session.c:2886 sofia/internal/1000@159.89.163.195:5020 skip receive message [PHONE_EVENT] (channel is hungup already) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:37.414836 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1000@159.89.163.195:5020) State EXECUTE going to sleep 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:37.414836 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@159.89.163.195:5020) Running State Change CS_HANGUP (Cur 2 Tot 23) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:37.414836 [DEBUG] switch_core_state_machine.c:847 (sofia/internal/1000@159.89.163.195:5020) Callstate Change ACTIVE -> HANGUP 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:37.414836 [DEBUG] switch_core_state_machine.c:849 (sofia/internal/1000@159.89.163.195:5020) State HANGUP 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:37.414836 [DEBUG] mod_sofia.c:443 sofia/internal/1000@159.89.163.195:5020 Overriding SIP cause 480 with 200 from the other leg 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:37.414836 [DEBUG] mod_sofia.c:449 Channel sofia/internal/1000@159.89.163.195:5020 hanging up, cause: NORMAL_CLEARING 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:37.414836 [DEBUG] mod_sofia.c:502 Sending BYE to sofia/internal/1000@159.89.163.195:5020 send 642 bytes to udp/[183.82.203.220]:23502 at 12:26:37.417679: ------------------------------------------------------------------------ BYE sip:1000@183.82.203.220:23502;rinstance=455085c26772fb89 SIP/2.0 Via: SIP/2.0/UDP 159.89.163.195:5020;rport;branch=z9hG4bKvQv97HaKUFmHm Max-Forwards: 70 From: ;tag=c4atgm4tm8Q0g To: "1000" ;tag=34407550 Call-ID: 92627MzJlOWE2MzNlZDM5ODhkZTc4YzJjZGM2YmFlZDdhNTU CSeq: 130124134 BYE User-Agent: FreeSWITCH-mod_sofia/1.8.2+git~20180926T175525Z~a98a958ac3~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Reason: Q.850;cause=16;text="NORMAL_CLEARING" Content-Length: 0 ------------------------------------------------------------------------ 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:37.414836 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1000@159.89.163.195:5020 Standard HANGUP, cause: NORMAL_CLEARING 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:37.414836 [DEBUG] switch_core_state_machine.c:849 (sofia/internal/1000@159.89.163.195:5020) State HANGUP going to sleep 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:37.414836 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1000@159.89.163.195:5020) State Change CS_HANGUP -> CS_REPORTING 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:37.414836 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@159.89.163.195:5020) Running State Change CS_REPORTING (Cur 2 Tot 23) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:37.414836 [DEBUG] switch_core_state_machine.c:935 (sofia/internal/1000@159.89.163.195:5020) State REPORTING 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:37.414836 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1000@159.89.163.195:5020 Standard REPORTING, cause: NORMAL_CLEARING 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:37.414836 [DEBUG] switch_core_state_machine.c:935 (sofia/internal/1000@159.89.163.195:5020) State REPORTING going to sleep 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:37.414836 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1000@159.89.163.195:5020) State Change CS_REPORTING -> CS_DESTROY 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:37.414836 [DEBUG] switch_core_session.c:1714 Session 22 (sofia/internal/1000@159.89.163.195:5020) Locked, Waiting on external entities 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:37.414836 [NOTICE] switch_core_session.c:1732 Session 22 (sofia/internal/1000@159.89.163.195:5020) Ended 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:37.414836 [NOTICE] switch_core_session.c:1736 Close Channel sofia/internal/1000@159.89.163.195:5020 [CS_DESTROY] 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:37.414836 [DEBUG] switch_core_state_machine.c:738 (sofia/internal/1000@159.89.163.195:5020) Running State Change CS_DESTROY (Cur 1 Tot 23) 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:37.414836 [DEBUG] switch_core_state_machine.c:748 (sofia/internal/1000@159.89.163.195:5020) State DESTROY 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:37.414836 [DEBUG] mod_sofia.c:354 sofia/internal/1000@159.89.163.195:5020 SOFIA DESTROY 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:37.414836 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1000@159.89.163.195:5020 Standard DESTROY 18923368-a8a9-4a94-9b9f-dcceaca1e6c8 2018-10-30 12:26:37.414836 [DEBUG] switch_core_state_machine.c:748 (sofia/internal/1000@159.89.163.195:5020) State DESTROY going to sleep 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:37.414836 [NOTICE] switch_core_session.c:1732 Session 23 (sofia/internal/1003@183.82.203.220:23585) Ended 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:37.414836 [NOTICE] switch_core_session.c:1736 Close Channel sofia/internal/1003@183.82.203.220:23585 [CS_DESTROY] 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:37.414836 [DEBUG] switch_core_state_machine.c:738 (sofia/internal/1003@183.82.203.220:23585) Running State Change CS_DESTROY (Cur 0 Tot 23) 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:37.414836 [DEBUG] switch_core_state_machine.c:748 (sofia/internal/1003@183.82.203.220:23585) State DESTROY 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:37.414836 [DEBUG] mod_sofia.c:354 sofia/internal/1003@183.82.203.220:23585 SOFIA DESTROY 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:37.414836 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1003@183.82.203.220:23585 Standard DESTROY 14a8bd6f-af2e-4b1d-8d18-bd59d863387f 2018-10-30 12:26:37.414836 [DEBUG] switch_core_state_machine.c:748 (sofia/internal/1003@183.82.203.220:23585) State DESTROY going to sleep recv 420 bytes from udp/[183.82.203.220]:23502 at 12:26:37.505861: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 159.89.163.195:5020;rport=5020;branch=z9hG4bKvQv97HaKUFmHm Contact: To: "1000";tag=34407550 From: ;tag=c4atgm4tm8Q0g Call-ID: 92627MzJlOWE2MzNlZDM5ODhkZTc4YzJjZGM2YmFlZDdhNTU CSeq: 130124134 BYE User-Agent: X-Lite release 5.3.2 stamp 92627 Content-Length: 0