recv 796 bytes from udp/[183.82.203.220]:23502 at 12:34:12.381923:
------------------------------------------------------------------------
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---f7a8f15b6eab5e05;rport
Max-Forwards: 70
Contact: <sip:1000@183.82.203.220:23502;rinstance=455085c26772fb89>
To: <sip:1000@159.89.163.195:5020>
From: "1000"<sip:1000@159.89.163.195:5020>;tag=e2818c43
Call-ID: 92627YjA3OTQ1NGE2MmZlZmI1NDNkNzhlNTcyODM4ZjU5MWQ
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=- 13185394425892273 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 64120 RTP/AVP 0 101
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
------------------------------------------------------------------------
2018-10-30 12:34:12.374828 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1000@159.89.163.195:5020 [b518fc28-5c14-4367-9326-94767a8e0783]
2018-10-30 12:34:12.374828 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@159.89.163.195:5020) Running State Change CS_NEW (Cur 1 Tot 24)
2018-10-30 12:34:12.374828 [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:34:12.374828 [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:34:12.382884:
------------------------------------------------------------------------
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP 192.168.1.4:64343;branch=z9hG4bK-524287-1---f7a8f15b6eab5e05;rport=23502;received=183.82.203.220
From: "1000"<sip:1000@159.89.163.195:5020>;tag=e2818c43
To: <sip:1000@159.89.163.195:5020>;tag=FZp4N5p5B3trK
Call-ID: 92627YjA3OTQ1NGE2MmZlZmI1NDNkNzhlNTcyODM4ZjU5MWQ
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="3d21ebdb-1f85-4cfa-b808-5ebb75c487ff", algorithm=MD5, qop="auth"
Content-Length: 0
------------------------------------------------------------------------
2018-10-30 12:34:12.374828 [DEBUG] sofia.c:2413 detaching session b518fc28-5c14-4367-9326-94767a8e0783
2018-10-30 12:34:12.374828 [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:34:12.410143:
------------------------------------------------------------------------
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---f7a8f15b6eab5e05;rport
Max-Forwards: 70
To: <sip:1000@159.89.163.195:5020>;tag=FZp4N5p5B3trK
From: "1000"<sip:1000@159.89.163.195:5020>;tag=e2818c43
Call-ID: 92627YjA3OTQ1NGE2MmZlZmI1NDNkNzhlNTcyODM4ZjU5MWQ
CSeq: 1 ACK
Content-Length: 0
------------------------------------------------------------------------
recv 1065 bytes from udp/[183.82.203.220]:23502 at 12:34:12.412418:
------------------------------------------------------------------------
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---ad06303728d3f229;rport
Max-Forwards: 70
Contact: <sip:1000@183.82.203.220:23502;rinstance=455085c26772fb89>
To: <sip:1000@159.89.163.195:5020>
From: "1000"<sip:1000@159.89.163.195:5020>;tag=e2818c43
Call-ID: 92627YjA3OTQ1NGE2MmZlZmI1NDNkNzhlNTcyODM4ZjU5MWQ
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="3d21ebdb-1f85-4cfa-b808-5ebb75c487ff",uri="sip:1000@159.89.163.195:5020",response="51408f634a6b75ba28e86588ed92fb0e",cnonce="b2f918df319453bb78cab0b218f67280",nc=00000001,qop=auth,algorithm=MD5
Supported: replaces
User-Agent: X-Lite release 5.3.2 stamp 92627
Content-Length: 207
v=0
o=- 13185394425892273 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 64120 RTP/AVP 0 101
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
------------------------------------------------------------------------
2018-10-30 12:34:12.404804 [DEBUG] sofia.c:2522 Re-attaching to session b518fc28-5c14-4367-9326-94767a8e0783
2018-10-30 12:34:12.414811 [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:34:12.414811 [DEBUG] sofia.c:10251 IP 183.82.203.220 Rejected by acl "domains". Falling back to Digest auth.
2018-10-30 12:34:12.414811 [DEBUG] sofia.c:11388 Setting NAT mode based on nat.auto
2018-10-30 12:34:12.414811 [DEBUG] sofia.c:7291 Channel sofia/internal/1000@159.89.163.195:5020 entering state [received][100]
2018-10-30 12:34:12.414811 [DEBUG] sofia.c:7301 Remote SDP:
v=0
o=- 13185394425892273 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 64120 RTP/AVP 0 101
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
2018-10-30 12:34:12.414811 [DEBUG] sofia.c:7695 (sofia/internal/1000@159.89.163.195:5020) State Change CS_NEW -> CS_INIT
2018-10-30 12:34:12.414811 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@159.89.163.195:5020) Running State Change CS_INIT (Cur 1 Tot 24)
2018-10-30 12:34:12.414811 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@159.89.163.195:5020) State INIT
2018-10-30 12:34:12.414811 [DEBUG] mod_sofia.c:93 sofia/internal/1000@159.89.163.195:5020 SOFIA INIT
2018-10-30 12:34:12.414811 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1000@159.89.163.195:5020 Standard INIT
2018-10-30 12:34:12.414811 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1000@159.89.163.195:5020) State Change CS_INIT -> CS_ROUTING
2018-10-30 12:34:12.414811 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@159.89.163.195:5020) State INIT going to sleep
2018-10-30 12:34:12.414811 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@159.89.163.195:5020) Running State Change CS_ROUTING (Cur 1 Tot 24)
2018-10-30 12:34:12.414811 [DEBUG] switch_channel.c:2249 (sofia/internal/1000@159.89.163.195:5020) Callstate Change DOWN -> RINGING
2018-10-30 12:34:12.414811 [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:34:12.424720:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.4:64343;branch=z9hG4bK-524287-1---ad06303728d3f229;rport=23502;received=183.82.203.220
From: "1000"<sip:1000@159.89.163.195:5020>;tag=e2818c43
To: <sip:1000@159.89.163.195:5020>
Call-ID: 92627YjA3OTQ1NGE2MmZlZmI1NDNkNzhlNTcyODM4ZjU5MWQ
CSeq: 2 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.8.2+git~20180926T175525Z~a98a958ac3~64bit
Content-Length: 0
------------------------------------------------------------------------
2018-10-30 12:34:12.424808 [DEBUG] mod_sofia.c:154 sofia/internal/1000@159.89.163.195:5020 SOFIA ROUTING
2018-10-30 12:34:12.424808 [DEBUG] switch_core_state_machine.c:236 sofia/internal/1000@159.89.163.195:5020 Standard ROUTING
2018-10-30 12:34:12.424808 [INFO] mod_dialplan_xml.c:637 Processing 1000 <1000>->1000 in context default
Dialplan: sofia/internal/1000@159.89.163.195:5020 parsing [default->ee634e42-e806-4e15-9abe-969d09a3eb33] continue=false
Dialplan: sofia/internal/1000@159.89.163.195:5020 Regex (PASS) [ee634e42-e806-4e15-9abe-969d09a3eb33] destination_number(1000) =~ /^1000$/ break=on-false
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action clear_digit_action(all)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action export(bind_digit_digit_timeout=200)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action unset(sip_h_X-Weave-DC)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action unset(sip_h_X-Loop-Data)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action unset(sip_h_X-Weave-External)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action unset(sip_h_X-Weave-Internal)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action unset(sip_h_X-Weave-Outbound)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action export(weave_domain=dev-scott)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action export(w_domain=dev-scott.getweave.io)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action export(selected_carrier=twilio)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_log=true)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_direction=inbound)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_dialed_number=8017970178)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_caller_name=Weave )
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_caller_number=7164186158)
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)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_auto_sms_webhook_key=4G7tEQa0CQB8XlXs-JkdiP3AFRBT3pIrG-hm0k1GK4QZMBzMM4)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action limit(hash dev-scott.getweave.io inbound 10 inbound_exceeded)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(w_cdr_originator=7164186158)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(w_cdr_destination=8017970178)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(w_cdr_direction=inbound)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(w_call_direction=inbound)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(RECORD_STEREO=true)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(media_bug_answer_req=true)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(recording_follow_transfer=true)
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')
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)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action export(location_id=94472cd8-2b1c-4b44-94fe-9708c2bd739d)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(weave_lookup_number=${caller_id_number})
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(continue_on_fail=true)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(hangup_after_bridge=true)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(hold_music=local_stream://moh)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(temp_hold_music=local_stream://moh)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_slug=dev-scott)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(generated_channel_id_eschmidbauer02_dev-scott=1a9b5231-e815-4aba-900d-ecf1089e848f)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_sip_id_eschmidbauer02_dev-scott=44ea632a-a36d-4f3e-b2cc-5272065d1d09)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_sip_name_eschmidbauer02_dev-scott=eschmidbauer02)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(generated_channel_id_eschmidbauer01_dev-scott=8f00162e-9926-4f19-a078-b88487aa6e58)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_sip_id_eschmidbauer01_dev-scott=126385ac-5c42-4b20-bc64-0eec19733a42)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_sip_name_eschmidbauer01_dev-scott=E-VVX400)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(generated_channel_id_xlite_dev-scott=f60035e5-788e-4acd-9d86-18f19ae75dec)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_sip_id_xlite_dev-scott=4073da9c-2359-4f2b-ae75-7fc06748ba78)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_sip_name_xlite_dev-scott=xlite)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(generated_channel_id_eschmidbauer03_dev-scott=f403f20c-cb2e-40f9-bde5-d1ad9e10616b)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_sip_id_eschmidbauer03_dev-scott=1fa6d75e-765e-4110-a8e1-13f7df9275c0)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_sip_name_eschmidbauer03_dev-scott=vvx500)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(generated_channel_id_testline05_dev-scott=3573a9a4-b04e-4ab1-92e8-dfaa401c1b85)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_sip_id_testline05_dev-scott=1b112711-e324-484a-bbc5-f17564d26935)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(cdr_sip_name_testline05_dev-scott=testline05)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(mobile_app=eschmidbauer01;xlite)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action set(desk_phone=eschmidbauer02;eschmidbauer03;testline05)
Dialplan: sofia/internal/1000@159.89.163.195:5020 Action bridge({origination_uuid=14a8bd6f-af2e-4b1d-8d18-bd59d863387f}user/1003@${domain_name})
2018-10-30 12:34:12.424808 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/1000@159.89.163.195:5020) State Change CS_ROUTING -> CS_EXECUTE
2018-10-30 12:34:12.424808 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@159.89.163.195:5020) State ROUTING going to sleep
2018-10-30 12:34:12.424808 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@159.89.163.195:5020) Running State Change CS_EXECUTE (Cur 1 Tot 24)
2018-10-30 12:34:12.424808 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1000@159.89.163.195:5020) State EXECUTE
2018-10-30 12:34:12.424808 [DEBUG] mod_sofia.c:209 sofia/internal/1000@159.89.163.195:5020 SOFIA EXECUTE
2018-10-30 12:34:12.424808 [DEBUG] switch_core_state_machine.c:328 sofia/internal/1000@159.89.163.195:5020 Standard EXECUTE
EXECUTE sofia/internal/1000@159.89.163.195:5020 clear_digit_action(all)
EXECUTE sofia/internal/1000@159.89.163.195:5020 export(bind_digit_digit_timeout=200)
2018-10-30 12:34:12.424808 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [bind_digit_digit_timeout]=[200]
EXECUTE sofia/internal/1000@159.89.163.195:5020 unset(sip_h_X-Weave-DC)
2018-10-30 12:34:12.424808 [DEBUG] mod_dptools.c:1743 UNSET [sip_h_X-Weave-DC]
EXECUTE sofia/internal/1000@159.89.163.195:5020 unset(sip_h_X-Loop-Data)
2018-10-30 12:34:12.424808 [DEBUG] mod_dptools.c:1743 UNSET [sip_h_X-Loop-Data]
EXECUTE sofia/internal/1000@159.89.163.195:5020 unset(sip_h_X-Weave-External)
2018-10-30 12:34:12.424808 [DEBUG] mod_dptools.c:1743 UNSET [sip_h_X-Weave-External]
EXECUTE sofia/internal/1000@159.89.163.195:5020 unset(sip_h_X-Weave-Internal)
2018-10-30 12:34:12.424808 [DEBUG] mod_dptools.c:1743 UNSET [sip_h_X-Weave-Internal]
EXECUTE sofia/internal/1000@159.89.163.195:5020 unset(sip_h_X-Weave-Outbound)
2018-10-30 12:34:12.424808 [DEBUG] mod_dptools.c:1743 UNSET [sip_h_X-Weave-Outbound]
EXECUTE sofia/internal/1000@159.89.163.195:5020 export(weave_domain=dev-scott)
2018-10-30 12:34:12.424808 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [weave_domain]=[dev-scott]
EXECUTE sofia/internal/1000@159.89.163.195:5020 export(w_domain=dev-scott.getweave.io)
2018-10-30 12:34:12.424808 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [w_domain]=[dev-scott.getweave.io]
EXECUTE sofia/internal/1000@159.89.163.195:5020 export(selected_carrier=twilio)
2018-10-30 12:34:12.424808 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [selected_carrier]=[twilio]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_log=true)
2018-10-30 12:34:12.424808 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_log]=[true]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_direction=inbound)
2018-10-30 12:34:12.424808 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_direction]=[inbound]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_dialed_number=8017970178)
2018-10-30 12:34:12.424808 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_dialed_number]=[8017970178]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_caller_name=Weave )
2018-10-30 12:34:12.424808 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_caller_name]=[Weave ]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_caller_number=7164186158)
2018-10-30 12:34:12.424808 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_caller_number]=[7164186158]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_auto_sms_webhook_url=http://admin-api.client:8000/portal/v1/phones/missedcall)
2018-10-30 12:34:12.424808 [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]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_auto_sms_webhook_key=4G7tEQa0CQB8XlXs-JkdiP3AFRBT3pIrG-hm0k1GK4QZMBzMM4)
2018-10-30 12:34:12.424808 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_auto_sms_webhook_key]=[4G7tEQa0CQB8XlXs-JkdiP3AFRBT3pIrG-hm0k1GK4QZMBzMM4]
EXECUTE sofia/internal/1000@159.89.163.195:5020 limit(hash dev-scott.getweave.io inbound 10 inbound_exceeded)
2018-10-30 12:34:12.424808 [DEBUG] switch_limit.c:126 incr called: dev-scott.getweave.io_inbound max:10, interval:0
2018-10-30 12:34:12.424808 [DEBUG] mod_hash.c:196 Usage for dev-scott.getweave.io_inbound is now 1/10
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(w_cdr_originator=7164186158)
2018-10-30 12:34:12.424808 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [w_cdr_originator]=[7164186158]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(w_cdr_destination=8017970178)
2018-10-30 12:34:12.424808 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [w_cdr_destination]=[8017970178]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(w_cdr_direction=inbound)
2018-10-30 12:34:12.424808 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [w_cdr_direction]=[inbound]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(w_call_direction=inbound)
2018-10-30 12:34:12.424808 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [w_call_direction]=[inbound]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(RECORD_STEREO=true)
2018-10-30 12:34:12.424808 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [RECORD_STEREO]=[true]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(media_bug_answer_req=true)
2018-10-30 12:34:12.424808 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [media_bug_answer_req]=[true]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(recording_follow_transfer=true)
2018-10-30 12:34:12.424808 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [recording_follow_transfer]=[true]
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')
2018-10-30 12:34:12.424808 [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']
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)
2018-10-30 12:34:12.424808 [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]
EXECUTE sofia/internal/1000@159.89.163.195:5020 export(location_id=94472cd8-2b1c-4b44-94fe-9708c2bd739d)
2018-10-30 12:34:12.424808 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [location_id]=[94472cd8-2b1c-4b44-94fe-9708c2bd739d]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(weave_lookup_number=1000)
2018-10-30 12:34:12.424808 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [weave_lookup_number]=[1000]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(continue_on_fail=true)
2018-10-30 12:34:12.424808 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [continue_on_fail]=[true]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(hangup_after_bridge=true)
2018-10-30 12:34:12.424808 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [hangup_after_bridge]=[true]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(hold_music=local_stream://moh)
2018-10-30 12:34:12.424808 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [hold_music]=[local_stream://moh]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(temp_hold_music=local_stream://moh)
2018-10-30 12:34:12.424808 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [temp_hold_music]=[local_stream://moh]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_slug=dev-scott)
2018-10-30 12:34:12.424808 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_slug]=[dev-scott]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(generated_channel_id_eschmidbauer02_dev-scott=1a9b5231-e815-4aba-900d-ecf1089e848f)
2018-10-30 12:34:12.424808 [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]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_sip_id_eschmidbauer02_dev-scott=44ea632a-a36d-4f3e-b2cc-5272065d1d09)
2018-10-30 12:34:12.424808 [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]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_sip_name_eschmidbauer02_dev-scott=eschmidbauer02)
2018-10-30 12:34:12.424808 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_sip_name_eschmidbauer02_dev-scott]=[eschmidbauer02]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(generated_channel_id_eschmidbauer01_dev-scott=8f00162e-9926-4f19-a078-b88487aa6e58)
2018-10-30 12:34:12.424808 [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]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_sip_id_eschmidbauer01_dev-scott=126385ac-5c42-4b20-bc64-0eec19733a42)
2018-10-30 12:34:12.424808 [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]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_sip_name_eschmidbauer01_dev-scott=E-VVX400)
2018-10-30 12:34:12.424808 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_sip_name_eschmidbauer01_dev-scott]=[E-VVX400]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(generated_channel_id_xlite_dev-scott=f60035e5-788e-4acd-9d86-18f19ae75dec)
2018-10-30 12:34:12.424808 [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]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_sip_id_xlite_dev-scott=4073da9c-2359-4f2b-ae75-7fc06748ba78)
2018-10-30 12:34:12.434805 [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]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_sip_name_xlite_dev-scott=xlite)
2018-10-30 12:34:12.434805 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_sip_name_xlite_dev-scott]=[xlite]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(generated_channel_id_eschmidbauer03_dev-scott=f403f20c-cb2e-40f9-bde5-d1ad9e10616b)
2018-10-30 12:34:12.434805 [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]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_sip_id_eschmidbauer03_dev-scott=1fa6d75e-765e-4110-a8e1-13f7df9275c0)
2018-10-30 12:34:12.434805 [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]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_sip_name_eschmidbauer03_dev-scott=vvx500)
2018-10-30 12:34:12.434805 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_sip_name_eschmidbauer03_dev-scott]=[vvx500]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(generated_channel_id_testline05_dev-scott=3573a9a4-b04e-4ab1-92e8-dfaa401c1b85)
2018-10-30 12:34:12.434805 [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]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_sip_id_testline05_dev-scott=1b112711-e324-484a-bbc5-f17564d26935)
2018-10-30 12:34:12.434805 [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]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(cdr_sip_name_testline05_dev-scott=testline05)
2018-10-30 12:34:12.434805 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [cdr_sip_name_testline05_dev-scott]=[testline05]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(mobile_app=eschmidbauer01;xlite)
2018-10-30 12:34:12.434805 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [mobile_app]=[eschmidbauer01;xlite]
EXECUTE sofia/internal/1000@159.89.163.195:5020 set(desk_phone=eschmidbauer02;eschmidbauer03;testline05)
2018-10-30 12:34:12.434805 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1000@159.89.163.195:5020 [desk_phone]=[eschmidbauer02;eschmidbauer03;testline05]
EXECUTE sofia/internal/1000@159.89.163.195:5020 bridge({origination_uuid=14a8bd6f-af2e-4b1d-8d18-bd59d863387f}user/1003@159.89.163.195)
2018-10-30 12:34:12.434805 [DEBUG] switch_channel.c:1250 sofia/internal/1000@159.89.163.195:5020 EXPORTING[export_vars] [bind_digit_digit_timeout]=[200] to event
2018-10-30 12:34:12.434805 [DEBUG] switch_channel.c:1250 sofia/internal/1000@159.89.163.195:5020 EXPORTING[export_vars] [weave_domain]=[dev-scott] to event
2018-10-30 12:34:12.434805 [DEBUG] switch_channel.c:1250 sofia/internal/1000@159.89.163.195:5020 EXPORTING[export_vars] [w_domain]=[dev-scott.getweave.io] to event
2018-10-30 12:34:12.434805 [DEBUG] switch_channel.c:1250 sofia/internal/1000@159.89.163.195:5020 EXPORTING[export_vars] [selected_carrier]=[twilio] to event
2018-10-30 12:34:12.434805 [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
2018-10-30 12:34:12.434805 [DEBUG] switch_ivr_originate.c:2204 Parsing global variables
2018-10-30 12:34:12.434805 [DEBUG] switch_channel.c:1250 sofia/internal/1000@159.89.163.195:5020 EXPORTING[export_vars] [bind_digit_digit_timeout]=[200] to event
2018-10-30 12:34:12.434805 [DEBUG] switch_channel.c:1250 sofia/internal/1000@159.89.163.195:5020 EXPORTING[export_vars] [weave_domain]=[dev-scott] to event
2018-10-30 12:34:12.434805 [DEBUG] switch_channel.c:1250 sofia/internal/1000@159.89.163.195:5020 EXPORTING[export_vars] [w_domain]=[dev-scott.getweave.io] to event
2018-10-30 12:34:12.434805 [DEBUG] switch_channel.c:1250 sofia/internal/1000@159.89.163.195:5020 EXPORTING[export_vars] [selected_carrier]=[twilio] to event
2018-10-30 12:34:12.434805 [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
2018-10-30 12:34:12.434805 [DEBUG] switch_ivr_originate.c:2204 Parsing global variables
2018-10-30 12:34:12.434805 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1003@183.82.203.220:23585 [14a8bd6f-af2e-4b1d-8d18-bd59d863387f]
2018-10-30 12:34:12.434805 [DEBUG] mod_sofia.c:5028 (sofia/internal/1003@183.82.203.220:23585) State Change CS_NEW -> CS_INIT
2018-10-30 12:34:12.434805 [DEBUG] switch_core_session.c:641 sofia/internal/1003@183.82.203.220:23585 set UUID=14a8bd6f-af2e-4b1d-8d18-bd59d863387f
2018-10-30 12:34:12.434805 [NOTICE] switch_ivr_originate.c:2944 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2018-10-30 12:34:12.434805 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@183.82.203.220:23585) Running State Change CS_INIT (Cur 2 Tot 25)
2018-10-30 12:34:12.434805 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1003@183.82.203.220:23585) State INIT
2018-10-30 12:34:12.434805 [DEBUG] mod_sofia.c:93 sofia/internal/1003@183.82.203.220:23585 SOFIA INIT
2018-10-30 12:34:12.434805 [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
Local SDP:
v=0
o=FreeSWITCH 1540898872 1540898873 IN IP4 159.89.163.195
s=FreeSWITCH
c=IN IP4 159.89.163.195
t=0 0
m=audio 21980 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
send 1287 bytes to tcp/[183.82.203.220]:23585 at 12:34:12.440692:
------------------------------------------------------------------------
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=z9hG4bKZj8KD3vXjaQ9p
Max-Forwards: 69
From: "Extension 1000" <sip:1000@159.89.163.195>;tag=HH9NSUrc6m7Xa
To: <sip:1003@183.82.203.220:23585;transport=TCP;rinstance=eff915fadb99c0b0>
Call-ID: db3d7dda-570c-1237-2b97-528373432f88
CSeq: 130124362 INVITE
Contact: <sip:mod_sofia@159.89.163.195:5020;transport=tcp>
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" <sip:1000@159.89.163.195>;party=calling;screen=yes;privacy=off
v=0
o=FreeSWITCH 1540898872 1540898873 IN IP4 159.89.163.195
s=FreeSWITCH
c=IN IP4 159.89.163.195
t=0 0
m=audio 21980 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
------------------------------------------------------------------------
2018-10-30 12:34:12.434805 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1003@183.82.203.220:23585 Standard INIT
2018-10-30 12:34:12.434805 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1003@183.82.203.220:23585) State Change CS_INIT -> CS_ROUTING
2018-10-30 12:34:12.434805 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1003@183.82.203.220:23585) State INIT going to sleep
2018-10-30 12:34:12.434805 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@183.82.203.220:23585) Running State Change CS_ROUTING (Cur 2 Tot 25)
2018-10-30 12:34:12.434805 [DEBUG] sofia.c:7291 Channel sofia/internal/1003@183.82.203.220:23585 entering state [calling][0]
2018-10-30 12:34:12.434805 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1003@183.82.203.220:23585) State ROUTING
2018-10-30 12:34:12.434805 [DEBUG] mod_sofia.c:154 sofia/internal/1003@183.82.203.220:23585 SOFIA ROUTING
2018-10-30 12:34:12.434805 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1003@183.82.203.220:23585) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2018-10-30 12:34:12.434805 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1003@183.82.203.220:23585) State ROUTING going to sleep
2018-10-30 12:34:12.434805 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@183.82.203.220:23585) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 25)
2018-10-30 12:34:12.434805 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1003@183.82.203.220:23585) State CONSUME_MEDIA
2018-10-30 12:34:12.434805 [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:34:13.118462:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/TCP 159.89.163.195:5020;branch=z9hG4bKZj8KD3vXjaQ9p
To: <sip:1003@183.82.203.220:23585;transport=TCP;rinstance=eff915fadb99c0b0>
From: "Extension 1000" <sip:1000@159.89.163.195>;tag=HH9NSUrc6m7Xa
Call-ID: db3d7dda-570c-1237-2b97-528373432f88
CSeq: 130124362 INVITE
Content-Length: 0
------------------------------------------------------------------------
recv 529 bytes from tcp/[183.82.203.220]:23585 at 12:34:13.928711:
------------------------------------------------------------------------
SIP/2.0 180 Ringing
Via: SIP/2.0/TCP 159.89.163.195:5020;branch=z9hG4bKZj8KD3vXjaQ9p
Contact: <sip:1003@183.82.203.220:23581>
To: <sip:1003@183.82.203.220:23585;transport=TCP;rinstance=eff915fadb99c0b0>;tag=435b9221
From: "Extension 1000" <sip:1000@159.89.163.195>;tag=HH9NSUrc6m7Xa
Call-ID: db3d7dda-570c-1237-2b97-528373432f88
CSeq: 130124362 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
------------------------------------------------------------------------
2018-10-30 12:34:13.924820 [DEBUG] sofia.c:7291 Channel sofia/internal/1003@183.82.203.220:23585 entering state [proceeding][180]
2018-10-30 12:34:13.924820 [NOTICE] sofia.c:7401 Ring-Ready sofia/internal/1003@183.82.203.220:23585!
2018-10-30 12:34:13.924820 [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:34:13.946352:
------------------------------------------------------------------------
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 192.168.1.4:64343;branch=z9hG4bK-524287-1---ad06303728d3f229;rport=23502;received=183.82.203.220
From: "1000"<sip:1000@159.89.163.195:5020>;tag=e2818c43
To: <sip:1000@159.89.163.195:5020>;tag=g8FXQ0788BHBF
Call-ID: 92627YjA3OTQ1NGE2MmZlZmI1NDNkNzhlNTcyODM4ZjU5MWQ
CSeq: 2 INVITE
Contact: <sip:1000@159.89.163.195:5020;transport=udp>
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" <sip:1000@159.89.163.195>;party=calling;privacy=off;screen=no
------------------------------------------------------------------------
2018-10-30 12:34:13.944813 [NOTICE] mod_sofia.c:2419 Ring-Ready sofia/internal/1000@159.89.163.195:5020!
2018-10-30 12:34:13.944813 [DEBUG] sofia.c:7291 Channel sofia/internal/1000@159.89.163.195:5020 entering state [early][180]
2018-10-30 12:34:13.944813 [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:34:16.919063:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/TCP 159.89.163.195:5020;branch=z9hG4bKZj8KD3vXjaQ9p
Contact: <sip:1003@183.82.203.220:23581>
To: <sip:1003@183.82.203.220:23585;transport=TCP;rinstance=eff915fadb99c0b0>;tag=435b9221
From: "Extension 1000" <sip:1000@159.89.163.195>;tag=HH9NSUrc6m7Xa
Call-ID: db3d7dda-570c-1237-2b97-528373432f88
CSeq: 130124362 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 24215 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
------------------------------------------------------------------------
2018-10-30 12:34:16.914819 [DEBUG] sofia.c:7291 Channel sofia/internal/1003@183.82.203.220:23585 entering state [completing][200]
2018-10-30 12:34:16.914819 [DEBUG] sofia.c:7301 Remote SDP:
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 24215 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
2018-10-30 12:34:16.914819 [NOTICE] sofia.c:7304 Pre-Answer sofia/internal/1003@183.82.203.220:23585!
2018-10-30 12:34:16.914819 [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:34:16.921025:
------------------------------------------------------------------------
ACK sip:1003@183.82.203.220:23581 SIP/2.0
Via: SIP/2.0/UDP 159.89.163.195:5020;rport;branch=z9hG4bK0U1cFyD1FKDvj
Max-Forwards: 70
From: "Extension 1000" <sip:1000@159.89.163.195>;tag=HH9NSUrc6m7Xa
To: <sip:1003@183.82.203.220:23585;transport=TCP;rinstance=eff915fadb99c0b0>;tag=435b9221
Call-ID: db3d7dda-570c-1237-2b97-528373432f88
CSeq: 130124362 ACK
Contact: <sip:mod_sofia@159.89.163.195:5020;transport=tcp>
Content-Length: 0
------------------------------------------------------------------------
2018-10-30 12:34:16.914819 [DEBUG] sofia.c:7291 Channel sofia/internal/1003@183.82.203.220:23585 entering state [ready][200]
2018-10-30 12:34:16.914819 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-10-30 12:34:16.914819 [DEBUG] switch_core_media.c:5533 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2018-10-30 12:34:16.914819 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
2018-10-30 12:34:16.914819 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-10-30 12:34:16.914819 [DEBUG] switch_core_media.c:5394 Set telephone-event payload to 101@8000
2018-10-30 12:34:16.914819 [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
2018-10-30 12:34:16.914819 [DEBUG] switch_core_codec.c:111 sofia/internal/1003@183.82.203.220:23585 Original read codec set to PCMU:0
2018-10-30 12:34:16.914819 [DEBUG] switch_core_media.c:5737 Set telephone-event payload to 101@8000
2018-10-30 12:34:16.914819 [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
2018-10-30 12:34:16.914819 [DEBUG] switch_core_media.c:8511 AUDIO RTP [sofia/internal/1003@183.82.203.220:23585] 159.89.163.195 port 21980 -> 183.82.203.220 port 24215 codec: 0 ms: 20
2018-10-30 12:34:16.914819 [DEBUG] switch_rtp.c:4300 Starting timer [soft] 160 bytes per 20ms
2018-10-30 12:34:16.914819 [DEBUG] switch_core_media.c:8815 sofia/internal/1003@183.82.203.220:23585 Set 2833 dtmf send payload to 101
2018-10-30 12:34:16.914819 [DEBUG] switch_core_media.c:8822 sofia/internal/1003@183.82.203.220:23585 Set 2833 dtmf receive payload to 101
2018-10-30 12:34:16.914819 [DEBUG] switch_core_media.c:8845 sofia/internal/1003@183.82.203.220:23585 Set rtp dtmf delay to 40
2018-10-30 12:34:16.914819 [NOTICE] sofia.c:8429 Channel [sofia/internal/1003@183.82.203.220:23585] has been answered
2018-10-30 12:34:16.924812 [DEBUG] switch_channel.c:3781 (sofia/internal/1003@183.82.203.220:23585) Callstate Change EARLY -> ACTIVE
2018-10-30 12:34:16.934820 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
2018-10-30 12:34:16.934820 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-10-30 12:34:16.934820 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-10-30 12:34:16.934820 [DEBUG] switch_core_media.c:5533 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2018-10-30 12:34:16.934820 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-10-30 12:34:16.934820 [DEBUG] switch_core_media.c:5394 Set telephone-event payload to 101@8000
2018-10-30 12:34:16.934820 [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
2018-10-30 12:34:16.934820 [DEBUG] switch_core_codec.c:111 sofia/internal/1000@159.89.163.195:5020 Original read codec set to PCMU:0
2018-10-30 12:34:16.934820 [DEBUG] switch_core_media.c:5737 Set telephone-event payload to 101@8000
2018-10-30 12:34:16.934820 [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
2018-10-30 12:34:16.934820 [DEBUG] switch_core_media.c:8511 AUDIO RTP [sofia/internal/1000@159.89.163.195:5020] 159.89.163.195 port 20662 -> 192.168.1.4 port 64120 codec: 0 ms: 20
2018-10-30 12:34:16.934820 [DEBUG] switch_rtp.c:4300 Starting timer [soft] 160 bytes per 20ms
2018-10-30 12:34:16.934820 [DEBUG] switch_core_media.c:8815 sofia/internal/1000@159.89.163.195:5020 Set 2833 dtmf send payload to 101
2018-10-30 12:34:16.934820 [DEBUG] switch_core_media.c:8822 sofia/internal/1000@159.89.163.195:5020 Set 2833 dtmf receive payload to 101
2018-10-30 12:34:16.934820 [DEBUG] switch_core_media.c:8845 sofia/internal/1000@159.89.163.195:5020 Set rtp dtmf delay to 40
2018-10-30 12:34:16.934820 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/1000@159.89.163.195:5020!
2018-10-30 12:34:16.934820 [DEBUG] switch_channel.c:3482 (sofia/internal/1000@159.89.163.195:5020) Callstate Change RINGING -> EARLY
2018-10-30 12:34:16.934820 [DEBUG] switch_core_media.c:8494 Audio params are unchanged for sofia/internal/1000@159.89.163.195:5020.
2018-10-30 12:34:16.934820 [DEBUG] mod_sofia.c:881 Local SDP sofia/internal/1000@159.89.163.195:5020:
v=0
o=FreeSWITCH 1540900194 1540900195 IN IP4 159.89.163.195
s=FreeSWITCH
c=IN IP4 159.89.163.195
t=0 0
m=audio 20662 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
send 1205 bytes to udp/[183.82.203.220]:23502 at 12:34:16.940321:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.4:64343;branch=z9hG4bK-524287-1---ad06303728d3f229;rport=23502;received=183.82.203.220
From: "1000"<sip:1000@159.89.163.195:5020>;tag=e2818c43
To: <sip:1000@159.89.163.195:5020>;tag=g8FXQ0788BHBF
Call-ID: 92627YjA3OTQ1NGE2MmZlZmI1NDNkNzhlNTcyODM4ZjU5MWQ
CSeq: 2 INVITE
Contact: <sip:1000@159.89.163.195:5020;transport=udp>
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" <sip:1003@159.89.163.195>;party=calling;privacy=off;screen=no
v=0
o=FreeSWITCH 1540900194 1540900195 IN IP4 159.89.163.195
s=FreeSWITCH
c=IN IP4 159.89.163.195
t=0 0
m=audio 20662 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
------------------------------------------------------------------------
2018-10-30 12:34:16.934820 [DEBUG] sofia.c:7291 Channel sofia/internal/1000@159.89.163.195:5020 entering state [completed][200]
2018-10-30 12:34:16.934820 [NOTICE] switch_ivr_originate.c:3740 Channel [sofia/internal/1000@159.89.163.195:5020] has been answered
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:34:16.934820 [ERR] switch_core_file.c:301 Invalid file format [mp3] for [/temp_recordings/dev-scott_2018-10-30_ee634e42-e806-4e15-9abe-969d09a3eb33.mp3]!
2018-10-30 12:34:16.934820 [ERR] switch_ivr_async.c:2737 Error opening /temp_recordings/dev-scott_2018-10-30_ee634e42-e806-4e15-9abe-969d09a3eb33.mp3
2018-10-30 12:34:16.934820 [DEBUG] switch_channel.c:3781 (sofia/internal/1000@159.89.163.195:5020) Callstate Change EARLY -> ACTIVE
2018-10-30 12:34:16.934820 [DEBUG] switch_ivr_originate.c:3798 Originate Resulted in Success: [sofia/internal/1003@183.82.203.220:23585]
2018-10-30 12:34:16.934820 [DEBUG] switch_ivr_originate.c:3798 Originate Resulted in Success: [sofia/internal/1003@183.82.203.220:23585]
2018-10-30 12:34:16.944808 [DEBUG] switch_ivr_bridge.c:1782 (sofia/internal/1003@183.82.203.220:23585) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
2018-10-30 12:34:16.944808 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@183.82.203.220:23585) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 25)
2018-10-30 12:34:16.944808 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/1003@183.82.203.220:23585) State EXCHANGE_MEDIA
2018-10-30 12:34:16.944808 [DEBUG] mod_sofia.c:645 SOFIA EXCHANGE_MEDIA
2018-10-30 12:34:17.014814 [DEBUG] switch_rtp.c:7550 Correct audio ip/port confirmed.
recv 478 bytes from udp/[183.82.203.220]:23502 at 12:34:17.056268:
------------------------------------------------------------------------
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---2a69633807c6d734;rport
Max-Forwards: 70
Contact: <sip:1000@183.82.203.220:23502;rinstance=455085c26772fb89>
To: <sip:1000@159.89.163.195:5020>;tag=g8FXQ0788BHBF
From: "1000"<sip:1000@159.89.163.195:5020>;tag=e2818c43
Call-ID: 92627YjA3OTQ1NGE2MmZlZmI1NDNkNzhlNTcyODM4ZjU5MWQ
CSeq: 2 ACK
User-Agent: X-Lite release 5.3.2 stamp 92627
Content-Length: 0
------------------------------------------------------------------------
2018-10-30 12:34:17.054818 [DEBUG] sofia.c:7291 Channel sofia/internal/1000@159.89.163.195:5020 entering state [ready][200]
2018-10-30 12:34:17.274823 [INFO] switch_rtp.c:7510 Auto Changing audio port from 192.168.1.4:64120 to 183.82.203.220:24218
recv 802 bytes from tcp/[183.82.203.220]:23585 at 12:34:17.342705:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/TCP 159.89.163.195:5020;branch=z9hG4bKZj8KD3vXjaQ9p
Contact: <sip:1003@183.82.203.220:23581>
To: <sip:1003@183.82.203.220:23585;transport=TCP;rinstance=eff915fadb99c0b0>;tag=435b9221
From: "Extension 1000" <sip:1000@159.89.163.195>;tag=HH9NSUrc6m7Xa
Call-ID: db3d7dda-570c-1237-2b97-528373432f88
CSeq: 130124362 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 24215 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:34:17.342834:
------------------------------------------------------------------------
ACK sip:1003@183.82.203.220:23581 SIP/2.0
Via: SIP/2.0/UDP 159.89.163.195:5020;rport;branch=z9hG4bK0U1cFyD1FKDvj
Max-Forwards: 70
From: "Extension 1000" <sip:1000@159.89.163.195>;tag=HH9NSUrc6m7Xa
To: <sip:1003@183.82.203.220:23585;transport=TCP;rinstance=eff915fadb99c0b0>;tag=435b9221
Call-ID: db3d7dda-570c-1237-2b97-528373432f88
CSeq: 130124362 ACK
Contact: <sip:mod_sofia@159.89.163.195:5020;transport=tcp>
Content-Length: 0
------------------------------------------------------------------------
recv 802 bytes from tcp/[183.82.203.220]:23585 at 12:34:18.346737:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/TCP 159.89.163.195:5020;branch=z9hG4bKZj8KD3vXjaQ9p
Contact: <sip:1003@183.82.203.220:23581>
To: <sip:1003@183.82.203.220:23585;transport=TCP;rinstance=eff915fadb99c0b0>;tag=435b9221
From: "Extension 1000" <sip:1000@159.89.163.195>;tag=HH9NSUrc6m7Xa
Call-ID: db3d7dda-570c-1237-2b97-528373432f88
CSeq: 130124362 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 24215 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:34:18.346849:
------------------------------------------------------------------------
ACK sip:1003@183.82.203.220:23581 SIP/2.0
Via: SIP/2.0/UDP 159.89.163.195:5020;rport;branch=z9hG4bK0U1cFyD1FKDvj
Max-Forwards: 70
From: "Extension 1000" <sip:1000@159.89.163.195>;tag=HH9NSUrc6m7Xa
To: <sip:1003@183.82.203.220:23585;transport=TCP;rinstance=eff915fadb99c0b0>;tag=435b9221
Call-ID: db3d7dda-570c-1237-2b97-528373432f88
CSeq: 130124362 ACK
Contact: <sip:mod_sofia@159.89.163.195:5020;transport=tcp>
Content-Length: 0
------------------------------------------------------------------------
recv 802 bytes from tcp/[183.82.203.220]:23585 at 12:34:20.345601:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/TCP 159.89.163.195:5020;branch=z9hG4bKZj8KD3vXjaQ9p
Contact: <sip:1003@183.82.203.220:23581>
To: <sip:1003@183.82.203.220:23585;transport=TCP;rinstance=eff915fadb99c0b0>;tag=435b9221
From: "Extension 1000" <sip:1000@159.89.163.195>;tag=HH9NSUrc6m7Xa
Call-ID: db3d7dda-570c-1237-2b97-528373432f88
CSeq: 130124362 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 24215 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:34:20.345717:
------------------------------------------------------------------------
ACK sip:1003@183.82.203.220:23581 SIP/2.0
Via: SIP/2.0/UDP 159.89.163.195:5020;rport;branch=z9hG4bK0U1cFyD1FKDvj
Max-Forwards: 70
From: "Extension 1000" <sip:1000@159.89.163.195>;tag=HH9NSUrc6m7Xa
To: <sip:1003@183.82.203.220:23585;transport=TCP;rinstance=eff915fadb99c0b0>;tag=435b9221
Call-ID: db3d7dda-570c-1237-2b97-528373432f88
CSeq: 130124362 ACK
Contact: <sip:mod_sofia@159.89.163.195:5020;transport=tcp>
Content-Length: 0
------------------------------------------------------------------------
recv 802 bytes from tcp/[183.82.203.220]:23585 at 12:34:24.347363:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/TCP 159.89.163.195:5020;branch=z9hG4bKZj8KD3vXjaQ9p
Contact: <sip:1003@183.82.203.220:23581>
To: <sip:1003@183.82.203.220:23585;transport=TCP;rinstance=eff915fadb99c0b0>;tag=435b9221
From: "Extension 1000" <sip:1000@159.89.163.195>;tag=HH9NSUrc6m7Xa
Call-ID: db3d7dda-570c-1237-2b97-528373432f88
CSeq: 130124362 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 24215 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:34:24.347512:
------------------------------------------------------------------------
ACK sip:1003@183.82.203.220:23581 SIP/2.0
Via: SIP/2.0/UDP 159.89.163.195:5020;rport;branch=z9hG4bK0U1cFyD1FKDvj
Max-Forwards: 70
From: "Extension 1000" <sip:1000@159.89.163.195>;tag=HH9NSUrc6m7Xa
To: <sip:1003@183.82.203.220:23585;transport=TCP;rinstance=eff915fadb99c0b0>;tag=435b9221
Call-ID: db3d7dda-570c-1237-2b97-528373432f88
CSeq: 130124362 ACK
Contact: <sip:mod_sofia@159.89.163.195:5020;transport=tcp>
Content-Length: 0
------------------------------------------------------------------------
freeswitch@shashi> ...