freeswitch@fusion.pbx> sofia profile internal siptrace on Enabled sip debugging on internal recv 994 bytes from tcp/[172.23.3.29]:52335 at 12:44:36.099788: ------------------------------------------------------------------------ INVITE sip:223@avengers.fusion.pbx;user=phone;transport=tcp SIP/2.0 Via: SIP/2.0/TCP 172.23.3.29;branch=z9hG4bK2eb32f1646DC2981 From: "hulk" ;tag=C072B00C-6643877F To: CSeq: 1 INVITE Call-ID: df58cf91afd08662d3aa437c04c34469 Contact: Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,INFO,MESSAGE,SUBSCRIBE,NOTIFY,PRACK,UPDATE,REFER User-Agent: PolycomVVX-VVX_310-UA/5.8.0.12848 Accept-Language: en Supported: replaces,100rel Allow-Events: conference,talk,hold Max-Forwards: 70 Content-Type: application/sdp Content-Length: 348 v=0 o=- 1533141877 1533141877 IN IP4 172.23.3.29 s=Polycom IP Phone c=IN IP4 172.23.3.29 t=0 0 a=sendrecv m=audio 2234 RTP/AVP 9 102 0 8 18 127 a=rtpmap:9 G722/8000 a=rtpmap:102 G7221/16000 a=fmtp:102 bitrate=32000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:127 telephone-event/8000 ------------------------------------------------------------------------ send 314 bytes to tcp/[172.23.3.29]:52335 at 12:44:36.099996: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/TCP 172.23.3.29;branch=z9hG4bK2eb32f1646DC2981;rport=52335 From: "hulk" ;tag=C072B00C-6643877F To: Call-ID: df58cf91afd08662d3aa437c04c34469 CSeq: 1 INVITE User-Agent: FreeSWITCH Content-Length: 0 ------------------------------------------------------------------------ 2018-08-01 12:44:36.084645 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/hulk@avengers.fusion.pbx [2ca83882-95aa-11e8-b704-815e756dd19a] 2018-08-01 12:44:36.084645 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/hulk@avengers.fusion.pbx) Running State Change CS_NEW (Cur 1 Tot 633) 2018-08-01 12:44:36.084645 [DEBUG] sofia.c:9873 sofia/internal/hulk@avengers.fusion.pbx receiving invite from 172.23.3.29:52335 version: 1.6.20 64bit 2018-08-01 12:44:36.084645 [DEBUG] sofia.c:10044 IP 172.23.3.29 Rejected by acl "domains". Falling back to Digest auth. send 826 bytes to tcp/[172.23.3.29]:52335 at 12:44:36.101148: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/TCP 172.23.3.29;branch=z9hG4bK2eb32f1646DC2981;rport=52335 From: "hulk" ;tag=C072B00C-6643877F To: ;tag=a41at9rDtZ7KQ Call-ID: df58cf91afd08662d3aa437c04c34469 CSeq: 1 INVITE User-Agent: FreeSWITCH 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="avengers.fusion.pbx", nonce="2ca85326-95aa-11e8-b705-815e756dd19a", algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ 2018-08-01 12:44:36.084645 [DEBUG] sofia.c:2334 detaching session 2ca83882-95aa-11e8-b704-815e756dd19a 2018-08-01 12:44:36.084645 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [223@avengers.fusion.pbx] from ip 172.23.3.29 2018-08-01 12:44:36.084645 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/hulk@avengers.fusion.pbx) State NEW recv 561 bytes from tcp/[172.23.3.29]:52335 at 12:44:36.140302: ------------------------------------------------------------------------ ACK sip:223@avengers.fusion.pbx;user=phone;transport=tcp SIP/2.0 Via: SIP/2.0/TCP 172.23.3.29;branch=z9hG4bK2eb32f1646DC2981 From: "hulk" ;tag=C072B00C-6643877F To: ;tag=a41at9rDtZ7KQ CSeq: 1 ACK Call-ID: df58cf91afd08662d3aa437c04c34469 Contact: Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,INFO,MESSAGE,SUBSCRIBE,NOTIFY,PRACK,UPDATE,REFER User-Agent: PolycomVVX-VVX_310-UA/5.8.0.12848 Accept-Language: en Max-Forwards: 70 Content-Length: 0 ------------------------------------------------------------------------ recv 1287 bytes from tcp/[172.23.3.29]:52335 at 12:44:36.183958: ------------------------------------------------------------------------ INVITE sip:223@avengers.fusion.pbx;user=phone;transport=tcp SIP/2.0 Via: SIP/2.0/TCP 172.23.3.29;branch=z9hG4bKb0ee65b03D82E1D3 From: "hulk" ;tag=C072B00C-6643877F To: CSeq: 2 INVITE Call-ID: df58cf91afd08662d3aa437c04c34469 Contact: Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,INFO,MESSAGE,SUBSCRIBE,NOTIFY,PRACK,UPDATE,REFER User-Agent: PolycomVVX-VVX_310-UA/5.8.0.12848 Accept-Language: en Supported: replaces,100rel Allow-Events: conference,talk,hold Proxy-Authorization: Digest username="hulk", realm="avengers.fusion.pbx", nonce="2ca85326-95aa-11e8-b705-815e756dd19a", qop=auth, cnonce="xhLJz0eeBgEOHs5", nc=00000001, uri="sip:223@avengers.fusion.pbx;user=phone;transport=tcp", response="fa14b086edd2db4a6a914259e90eff29", algorithm=MD5 Max-Forwards: 70 Content-Type: application/sdp Content-Length: 348 v=0 o=- 1533141877 1533141877 IN IP4 172.23.3.29 s=Polycom IP Phone c=IN IP4 172.23.3.29 t=0 0 a=sendrecv m=audio 2234 RTP/AVP 9 102 0 8 18 127 a=rtpmap:9 G722/8000 a=rtpmap:102 G7221/16000 a=fmtp:102 bitrate=32000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:127 telephone-event/8000 ------------------------------------------------------------------------ send 314 bytes to tcp/[172.23.3.29]:52335 at 12:44:36.184158: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/TCP 172.23.3.29;branch=z9hG4bKb0ee65b03D82E1D3;rport=52335 From: "hulk" ;tag=C072B00C-6643877F To: Call-ID: df58cf91afd08662d3aa437c04c34469 CSeq: 2 INVITE User-Agent: FreeSWITCH Content-Length: 0 ------------------------------------------------------------------------ 2018-08-01 12:44:36.164644 [DEBUG] sofia.c:2442 Re-attaching to session 2ca83882-95aa-11e8-b704-815e756dd19a 2018-08-01 12:44:36.184637 [DEBUG] sofia.c:9873 sofia/internal/hulk@avengers.fusion.pbx receiving invite from 172.23.3.29:52335 version: 1.6.20 64bit 2018-08-01 12:44:36.184637 [DEBUG] sofia.c:10044 IP 172.23.3.29 Rejected by acl "domains". Falling back to Digest auth. 2018-08-01 12:44:36.204669 [DEBUG] sofia.c:7084 Channel sofia/internal/hulk@avengers.fusion.pbx entering state [received][100] 2018-08-01 12:44:36.204669 [DEBUG] sofia.c:7094 Remote SDP: v=0 o=- 1533141877 1533141877 IN IP4 172.23.3.29 s=Polycom IP Phone c=IN IP4 172.23.3.29 t=0 0 a=sendrecv m=audio 2234 RTP/AVP 9 102 0 8 18 127 a=rtpmap:9 G722/8000 a=rtpmap:102 G7221/16000 a=fmtp:102 bitrate=32000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:127 telephone-event/8000 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[G7221:115:32000:20:48000:1] 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[G7221:107:16000:20:32000:1] 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G7221:102:16000:20:32000:1]/[G7221:115:32000:20:48000:1] 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G7221:102:16000:20:32000:1]/[G7221:107:16000:20:32000:1] 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [G7221:107:16000:20:32000:1] ++++ is saved as a match 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G7221:102:16000:20:32000:1]/[G722:9:8000:20:64000:1] 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G7221:102:16000:20:32000:1]/[PCMU:0:8000:20:64000:1] 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G7221:102:16000:20:32000:1]/[PCMA:8:8000:20:64000:1] 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G7221:115:32000:20:48000:1] 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G7221:107:16000:20:32000:1] 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G7221:115:32000:20:48000:1] 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G7221:107:16000:20:32000:1] 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[G7221:115:32000:20:48000:1] 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[G7221:107:16000:20:32000:1] 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1] 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1] 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1] 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 127@8000 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:3061 Set Codec sofia/internal/hulk@avengers.fusion.pbx G722/8000 20 ms 160 samples 64000 bits 1 channels 2018-08-01 12:44:36.204669 [DEBUG] switch_core_codec.c:111 sofia/internal/hulk@avengers.fusion.pbx Original read codec set to G722:9 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 127@8000 2018-08-01 12:44:36.204669 [DEBUG] switch_core_media.c:4767 sofia/internal/hulk@avengers.fusion.pbx Set 2833 dtmf send payload to 127 recv payload to 127 2018-08-01 12:44:36.204669 [DEBUG] sofia.c:7507 (sofia/internal/hulk@avengers.fusion.pbx) State Change CS_NEW -> CS_INIT 2018-08-01 12:44:36.204669 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/hulk@avengers.fusion.pbx) Running State Change CS_INIT (Cur 1 Tot 633) 2018-08-01 12:44:36.204669 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/hulk@avengers.fusion.pbx) State INIT 2018-08-01 12:44:36.204669 [DEBUG] mod_sofia.c:90 sofia/internal/hulk@avengers.fusion.pbx SOFIA INIT 2018-08-01 12:44:36.204669 [DEBUG] switch_core_state_machine.c:40 sofia/internal/hulk@avengers.fusion.pbx Standard INIT 2018-08-01 12:44:36.204669 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/hulk@avengers.fusion.pbx) State Change CS_INIT -> CS_ROUTING 2018-08-01 12:44:36.204669 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/hulk@avengers.fusion.pbx) State INIT going to sleep 2018-08-01 12:44:36.204669 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/hulk@avengers.fusion.pbx) Running State Change CS_ROUTING (Cur 1 Tot 633) 2018-08-01 12:44:36.204669 [DEBUG] switch_channel.c:2249 (sofia/internal/hulk@avengers.fusion.pbx) Callstate Change DOWN -> RINGING 2018-08-01 12:44:36.204669 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/hulk@avengers.fusion.pbx) State ROUTING 2018-08-01 12:44:36.204669 [DEBUG] mod_sofia.c:143 sofia/internal/hulk@avengers.fusion.pbx SOFIA ROUTING 2018-08-01 12:44:36.204669 [DEBUG] switch_core_state_machine.c:236 sofia/internal/hulk@avengers.fusion.pbx Standard ROUTING 2018-08-01 12:44:36.204669 [INFO] mod_dialplan_xml.c:637 Processing hulk ->223 in context avengers.fusion.pbx Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->Toll_Block] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [Toll_Block] ${user_exists}() =~ /false/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->user_exists] continue=true Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (PASS) [user_exists] () =~ // break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(user_exists=true) 2018-08-01 12:44:36.204669 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [user_exists]=[true] Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (PASS) [user_exists] ${user_exists}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(extension_uuid=${user_data ${destination_number}@${domain_name} var extension_uuid}) INLINE EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(extension_uuid=80678b40-6245-40f8-8f31-2fbad80fb005) 2018-08-01 12:44:36.224639 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [extension_uuid]=[80678b40-6245-40f8-8f31-2fbad80fb005] Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(hold_music=${user_data ${destination_number}@${domain_name} var hold_music}) INLINE EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(hold_music=) 2018-08-01 12:44:36.224639 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [hold_music]=[UNDEF] Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(forward_all_enabled=${user_data ${destination_number}@${domain_name} var forward_all_enabled}) INLINE EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(forward_all_enabled=) 2018-08-01 12:44:36.224639 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [forward_all_enabled]=[UNDEF] Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(forward_all_destination=${user_data ${destination_number}@${domain_name} var forward_all_destination}) INLINE EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(forward_all_destination=) 2018-08-01 12:44:36.224639 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [forward_all_destination]=[UNDEF] Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(forward_busy_enabled=${user_data ${destination_number}@${domain_name} var forward_busy_enabled}) INLINE EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(forward_busy_enabled=) 2018-08-01 12:44:36.224639 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [forward_busy_enabled]=[UNDEF] Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(forward_busy_destination=${user_data ${destination_number}@${domain_name} var forward_busy_destination}) INLINE EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(forward_busy_destination=) 2018-08-01 12:44:36.244633 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [forward_busy_destination]=[UNDEF] Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(forward_no_answer_enabled=${user_data ${destination_number}@${domain_name} var forward_no_answer_enabled}) INLINE EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(forward_no_answer_enabled=) 2018-08-01 12:44:36.244633 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [forward_no_answer_enabled]=[UNDEF] Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(forward_no_answer_destination=${user_data ${destination_number}@${domain_name} var forward_no_answer_destination}) INLINE EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(forward_no_answer_destination=) 2018-08-01 12:44:36.244633 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [forward_no_answer_destination]=[UNDEF] Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(forward_user_not_registered_enabled=${user_data ${destination_number}@${domain_name} var forward_user_not_registered_enabled}) INLINE EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(forward_user_not_registered_enabled=) 2018-08-01 12:44:36.244633 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [forward_user_not_registered_enabled]=[UNDEF] Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(forward_user_not_registered_destination=${user_data ${destination_number}@${domain_name} var forward_user_not_registered_destination}) INLINE EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(forward_user_not_registered_destination=) 2018-08-01 12:44:36.244633 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [forward_user_not_registered_destination]=[UNDEF] Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(do_not_disturb=${user_data ${destination_number}@${domain_name} var do_not_disturb}) INLINE EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(do_not_disturb=) 2018-08-01 12:44:36.244633 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [do_not_disturb]=[UNDEF] Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(call_timeout=${user_data ${destination_number}@${domain_name} var call_timeout}) INLINE EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(call_timeout=30) 2018-08-01 12:44:36.264641 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [call_timeout]=[30] Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(missed_call_app=${user_data ${destination_number}@${domain_name} var missed_call_app}) INLINE EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(missed_call_app=) 2018-08-01 12:44:36.264641 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [missed_call_app]=[UNDEF] Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(missed_call_data=${user_data ${destination_number}@${domain_name} var missed_call_data}) INLINE EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(missed_call_data=) 2018-08-01 12:44:36.264641 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [missed_call_data]=[UNDEF] Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(toll_allow=${user_data ${destination_number}@${domain_name} var toll_allow}) INLINE EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(toll_allow=) 2018-08-01 12:44:36.264641 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [toll_allow]=[UNDEF] Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(call_screen_enabled=${user_data ${destination_number}@${domain_name} var call_screen_enabled}) INLINE EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(call_screen_enabled=false) 2018-08-01 12:44:36.284640 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [call_screen_enabled]=[false] Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->caller-details] continue=true Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (PASS) [caller-details] ${caller_destination}() =~ /^$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(caller_destination=${destination_number}) INLINE EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(caller_destination=223) 2018-08-01 12:44:36.284640 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [caller_destination]=[223] Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(caller_id_name=${caller_id_name}) INLINE EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(caller_id_name=hulk) 2018-08-01 12:44:36.284640 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [caller_id_name]=[hulk] Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(caller_id_number=${caller_id_number}) INLINE EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(caller_id_number=222) 2018-08-01 12:44:36.284640 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [caller_id_number]=[222] Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->call-direction] continue=true Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [call-direction] ${call_direction}() =~ /^(inbound|outbound|local)$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx ANTI-Action export(call_direction=local) Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->variables] continue=true Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (PASS) [variables] () =~ // break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action export(origination_callee_id_name=${destination_number}) Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->user_record] continue=true Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (PASS) [user_record] () =~ // break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(user_record=${user_data ${destination_number}@${domain_name} var user_record}) INLINE EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(user_record=) 2018-08-01 12:44:36.284640 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [user_record]=[UNDEF] Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(from_user_exists=true) 2018-08-01 12:44:36.284640 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [from_user_exists]=[true] Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (PASS) [user_record] ${user_exists}(true) =~ /^true$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (PASS) [user_record] ${user_exists}(true) =~ /^true$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [user_record] ${call_direction}() =~ /^inbound$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (PASS) [user_record] ${user_exists}(true) =~ /^true$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [user_record] ${call_direction}() =~ /^outbound$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (PASS) [user_record] ${user_exists}(true) =~ /^true$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [user_record] ${call_direction}() =~ /^local$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(from_user_record=${user_data ${sip_from_user}@${sip_from_host} var user_record}) INLINE EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(from_user_record=) 2018-08-01 12:44:36.284640 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [from_user_record]=[UNDEF] Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [user_record] ${call_direction}() =~ /^inbound$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [user_record] ${call_direction}() =~ /^outbound$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [user_record] ${call_direction}() =~ /^local$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->redial] continue=true Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [redial] destination_number(223) =~ /^(redial|\*870)$/ break=on-true Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (PASS) [redial] () =~ // break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->speed_dial] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [speed_dial] destination_number(223) =~ /^\*0(.*)$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->default_caller_id] continue=true Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (PASS) [default_caller_id] ${emergency_caller_id_number}() =~ /^$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(emergency_caller_id_name=${default_emergency_caller_id_name}) INLINE EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(emergency_caller_id_name=) 2018-08-01 12:44:36.284640 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [emergency_caller_id_name]=[UNDEF] Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(emergency_caller_id_number=${default_emergency_caller_id_number}) INLINE EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(emergency_caller_id_number=) 2018-08-01 12:44:36.284640 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [emergency_caller_id_number]=[UNDEF] Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (PASS) [default_caller_id] ${outbound_caller_id_number}() =~ /^$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(outbound_caller_id_name=${default_outbound_caller_id_name}) INLINE EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(outbound_caller_id_name=) 2018-08-01 12:44:36.284640 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [outbound_caller_id_name]=[UNDEF] Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(outbound_caller_id_number=${default_outbound_caller_id_number}) INLINE EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(outbound_caller_id_number=) 2018-08-01 12:44:36.284640 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [outbound_caller_id_number]=[UNDEF] Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->Default_Route] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [Default_Route] ${user_exists}(true) =~ /false/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->ring group] continue= Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [ring group] destination_number(223) =~ /^202$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->Main] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [Main] destination_number(223) =~ /^212$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->ring group] continue= Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [ring group] destination_number(223) =~ /^201$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->agent_status] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [agent_status] destination_number(223) =~ /^\*22$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->agent_status_id] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [agent_status_id] destination_number(223) =~ /^\*23$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->group-intercept] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [group-intercept] destination_number(223) =~ /^\*8$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->page-extension] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [page-extension] destination_number(223) =~ /^\*8(\d{2,7})$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->eavesdrop] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [eavesdrop] destination_number(223) =~ /^\*33(\d{2,7})$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->call_privacy] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [call_privacy] destination_number(223) =~ /^\*67(\d+)$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->call_return] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [call_return] destination_number(223) =~ /^\*69$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->extension_queue] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [extension_queue] destination_number(223) =~ /^\*800(.*)$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->intercept-ext-polycom] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [intercept-ext-polycom] destination_number(223) =~ /^\*97(\d+)$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->intercept-ext] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [intercept-ext] destination_number(223) =~ /^\*\*(\d+)$/ break=on-true Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [intercept-ext] destination_number(223) =~ /^\*\*$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->dx] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [dx] destination_number(223) =~ /^dx$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->send_to_voicemail] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [send_to_voicemail] destination_number(223) =~ /^\*99(\d{2,10})$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->att_xfer] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [att_xfer] destination_number(223) =~ /^att_xfer$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->extension-to-voicemail] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (PASS) [extension-to-voicemail] ${user_exists}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [extension-to-voicemail] username(hulk) =~ /^222$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->vmain] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [vmain] destination_number(223) =~ /^vmain$|^\*4000$|^\*98$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [vmain] destination_number(223) =~ /^(vmain$|^\*4000$|^\*98)(\d{2,12})$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->xfer_vm] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [xfer_vm] destination_number(223) =~ /^xfer_vm$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->is_transfer] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [is_transfer] destination_number(223) =~ /^is_transfer$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->vmain_user] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [vmain_user] destination_number(223) =~ /^\*97$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->delay_echo] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [delay_echo] destination_number(223) =~ /^\*9195$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->cf] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [cf] destination_number(223) =~ /^cf$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->echo] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [echo] destination_number(223) =~ /^\*9196$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->milliwatt] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [milliwatt] destination_number(223) =~ /^\*9197$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->is_zrtp_secure] continue=true Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [is_zrtp_secure] ${zrtp_secure_media_confirmed}() =~ /^true$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx ANTI-Action eval(not_secure) Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->is_secure] continue=true Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [is_secure] ${sip_via_protocol}(tcp) =~ /tls/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->tone_stream] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [tone_stream] destination_number(223) =~ /^\*9198$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->hold_music] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [hold_music] destination_number(223) =~ /^\*9664$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->recordings] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [recordings] destination_number(223) =~ /^\*(732)$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->directory] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [directory] destination_number(223) =~ /^\*411$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->wake-up] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [wake-up] destination_number(223) =~ /^\*(925)$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->valet_park] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [valet_park] destination_number(223) =~ /^(park\+)?(\*59[0-9][0-9])$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [valet_park] ${sip_h_Referred-By}() =~ /sip:(.*)@.*/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [valet_park] destination_number(223) =~ /^(park\+)?(\*59[0-9][0-9])$/ break=never Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [valet_park] destination_number(223) =~ /^(park\+)?(\*59[0-9][0-9])$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->operator] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [operator] destination_number(223) =~ /^0$|^operator$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->operator-forward] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [operator-forward] destination_number(223) =~ /^\*000$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->do-not-disturb] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [do-not-disturb] destination_number(223) =~ /^\*77$/ break=on-true Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [do-not-disturb] destination_number(223) =~ /^\*78$|\*363$/ break=on-true Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [do-not-disturb] destination_number(223) =~ /^\*79$/ break=on-true Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [do-not-disturb] destination_number(223) =~ /^dnd\+222$/ break=on-true Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->call-forward] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [call-forward] destination_number(223) =~ /^\*72$/ break=on-true Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [call-forward] destination_number(223) =~ /^\*73$/ break=on-true Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [call-forward] destination_number(223) =~ /^\*74$/ break=on-true Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [call-forward] destination_number(223) =~ /^forward\+(\Q222\E)(?:\/(\d+))?$/ break=on-true Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->call forward all] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (PASS) [call forward all] ${user_exists}(true) =~ /true/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [call forward all] ${forward_all_enabled}() =~ /true/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->follow-me] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [follow-me] destination_number(223) =~ /^\*21$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->talking clock date and time] continue=true Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [talking clock date and time] destination_number(223) =~ /^\*9172$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->clear_sip_auto_answer] continue=true Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [clear_sip_auto_answer] ${click_to_call}() =~ /true/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->talking clock time] continue=true Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [talking clock time] destination_number(223) =~ /^\*9170$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->talking clock date] continue=true Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [talking clock date] destination_number(223) =~ /^\*9171$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->call_screen] continue=true Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (FAIL) [call_screen] ${call_screen_enabled}(false) =~ /^true$/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->local_extension] continue=true Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (PASS) [local_extension] ${user_exists}(true) =~ /true/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action export(dialed_extension=${destination_number}) INLINE EXECUTE sofia/internal/hulk@avengers.fusion.pbx export(dialed_extension=223) 2018-08-01 12:44:36.284640 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dialed_extension]=[223] Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action limit(hash ${domain_name} ${destination_number} ${limit_max} ${limit_destination}) Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (PASS) [local_extension] () =~ // break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(hangup_after_bridge=true) Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(continue_on_fail=true) Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number}) Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid}) Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(called_party_call_group=${user_data(${dialed_extension}@${domain_name} var call_group)}) Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action hash(insert/${domain_name}-last_dial/${called_party_call_group}/${uuid}) Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(api_hangup_hook=lua app.lua hangup) Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action export(domain_name=${domain_name}) Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action bridge(user/${destination_number}@${domain_name}) Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action lua(app.lua failure_handler) Dialplan: sofia/internal/hulk@avengers.fusion.pbx parsing [avengers.fusion.pbx->voicemail] continue=false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Regex (PASS) [voicemail] ${user_exists}(true) =~ /true/ break=on-false Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(voicemail_action=save) Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(voicemail_id=${destination_number}) Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action set(voicemail_profile=default) Dialplan: sofia/internal/hulk@avengers.fusion.pbx Action lua(app.lua voicemail) 2018-08-01 12:44:36.284640 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/hulk@avengers.fusion.pbx) State Change CS_ROUTING -> CS_EXECUTE 2018-08-01 12:44:36.284640 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/hulk@avengers.fusion.pbx) State ROUTING going to sleep 2018-08-01 12:44:36.284640 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/hulk@avengers.fusion.pbx) Running State Change CS_EXECUTE (Cur 1 Tot 633) 2018-08-01 12:44:36.284640 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/hulk@avengers.fusion.pbx) State EXECUTE 2018-08-01 12:44:36.284640 [DEBUG] mod_sofia.c:198 sofia/internal/hulk@avengers.fusion.pbx SOFIA EXECUTE 2018-08-01 12:44:36.284640 [DEBUG] switch_core_state_machine.c:328 sofia/internal/hulk@avengers.fusion.pbx Standard EXECUTE EXECUTE sofia/internal/hulk@avengers.fusion.pbx export(call_direction=local) 2018-08-01 12:44:36.284640 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [call_direction]=[local] EXECUTE sofia/internal/hulk@avengers.fusion.pbx export(origination_callee_id_name=223) 2018-08-01 12:44:36.284640 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [origination_callee_id_name]=[223] EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(RFC2822_DATE=Wed, 01 Aug 2018 12:44:36 -0400) 2018-08-01 12:44:36.284640 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [RFC2822_DATE]=[Wed, 01 Aug 2018 12:44:36 -0400] EXECUTE sofia/internal/hulk@avengers.fusion.pbx hash(insert/avengers.fusion.pbx-last_dial/222/223) EXECUTE sofia/internal/hulk@avengers.fusion.pbx eval(not_secure) EXECUTE sofia/internal/hulk@avengers.fusion.pbx limit(hash avengers.fusion.pbx 223 5 error/user_busy) 2018-08-01 12:44:36.284640 [DEBUG] switch_limit.c:126 incr called: avengers.fusion.pbx_223 max:5, interval:0 2018-08-01 12:44:36.284640 [DEBUG] mod_hash.c:196 Usage for avengers.fusion.pbx_223 is now 1/5 EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(hangup_after_bridge=true) 2018-08-01 12:44:36.284640 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [hangup_after_bridge]=[true] EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(continue_on_fail=true) 2018-08-01 12:44:36.284640 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [continue_on_fail]=[true] EXECUTE sofia/internal/hulk@avengers.fusion.pbx hash(insert/avengers.fusion.pbx-call_return/223/222) EXECUTE sofia/internal/hulk@avengers.fusion.pbx hash(insert/avengers.fusion.pbx-last_dial_ext/223/2ca83882-95aa-11e8-b704-815e756dd19a) EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(called_party_call_group=) 2018-08-01 12:44:36.304635 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [called_party_call_group]=[UNDEF] EXECUTE sofia/internal/hulk@avengers.fusion.pbx hash(insert/avengers.fusion.pbx-last_dial//2ca83882-95aa-11e8-b704-815e756dd19a) EXECUTE sofia/internal/hulk@avengers.fusion.pbx set(api_hangup_hook=lua app.lua hangup) 2018-08-01 12:44:36.304635 [DEBUG] mod_dptools.c:1548 SET sofia/internal/hulk@avengers.fusion.pbx [api_hangup_hook]=[lua app.lua hangup] EXECUTE sofia/internal/hulk@avengers.fusion.pbx export(domain_name=avengers.fusion.pbx) 2018-08-01 12:44:36.304635 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [domain_name]=[avengers.fusion.pbx] EXECUTE sofia/internal/hulk@avengers.fusion.pbx bridge(user/223@avengers.fusion.pbx) 2018-08-01 12:44:36.304635 [DEBUG] switch_channel.c:1250 sofia/internal/hulk@avengers.fusion.pbx EXPORTING[export_vars] [domain_name]=[avengers.fusion.pbx] to event 2018-08-01 12:44:36.304635 [DEBUG] switch_channel.c:1250 sofia/internal/hulk@avengers.fusion.pbx EXPORTING[export_vars] [dialed_extension]=[223] to event 2018-08-01 12:44:36.304635 [DEBUG] switch_channel.c:1250 sofia/internal/hulk@avengers.fusion.pbx EXPORTING[export_vars] [call_direction]=[local] to event 2018-08-01 12:44:36.304635 [DEBUG] switch_channel.c:1250 sofia/internal/hulk@avengers.fusion.pbx EXPORTING[export_vars] [origination_callee_id_name]=[223] to event 2018-08-01 12:44:36.304635 [DEBUG] switch_channel.c:1250 sofia/internal/hulk@avengers.fusion.pbx EXPORTING[export_vars] [domain_name]=[avengers.fusion.pbx] to event 2018-08-01 12:44:36.304635 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables 2018-08-01 12:44:36.304635 [DEBUG] switch_channel.c:1250 sofia/internal/hulk@avengers.fusion.pbx EXPORTING[export_vars] [domain_name]=[avengers.fusion.pbx] to event 2018-08-01 12:44:36.304635 [DEBUG] switch_channel.c:1250 sofia/internal/hulk@avengers.fusion.pbx EXPORTING[export_vars] [dialed_extension]=[223] to event 2018-08-01 12:44:36.304635 [DEBUG] switch_channel.c:1250 sofia/internal/hulk@avengers.fusion.pbx EXPORTING[export_vars] [call_direction]=[local] to event 2018-08-01 12:44:36.304635 [DEBUG] switch_channel.c:1250 sofia/internal/hulk@avengers.fusion.pbx EXPORTING[export_vars] [origination_callee_id_name]=[223] to event 2018-08-01 12:44:36.304635 [DEBUG] switch_channel.c:1250 sofia/internal/hulk@avengers.fusion.pbx EXPORTING[export_vars] [domain_name]=[avengers.fusion.pbx] to event 2018-08-01 12:44:36.304635 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables 2018-08-01 12:44:36.304635 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/Hawkeye@172.23.3.30 [2cc8fb9e-95aa-11e8-b736-815e756dd19a] 2018-08-01 12:44:36.304635 [DEBUG] mod_sofia.c:4819 (sofia/internal/Hawkeye@172.23.3.30) State Change CS_NEW -> CS_INIT 2018-08-01 12:44:36.304635 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/Hawkeye@172.23.3.30) Running State Change CS_INIT (Cur 2 Tot 634) 2018-08-01 12:44:36.304635 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/Hawkeye@172.23.3.30) State INIT 2018-08-01 12:44:36.304635 [DEBUG] mod_sofia.c:90 sofia/internal/Hawkeye@172.23.3.30 SOFIA INIT 2018-08-01 12:44:36.304635 [DEBUG] sofia_glue.c:1264 sip:Hawkeye@172.23.3.30:47079;transport=tcp Setting proxy route to sofia/internal/Hawkeye@172.23.3.30 2018-08-01 12:44:36.304635 [DEBUG] sofia_glue.c:1295 sofia/internal/Hawkeye@172.23.3.30 sending invite version: 1.6.20 64bit Local SDP: v=0 o=FreeSWITCH 1533119888 1533119889 IN IP4 10.66.77.88 s=FreeSWITCH c=IN IP4 10.66.77.88 t=0 0 m=audio 21988 RTP/AVP 9 102 103 0 8 101 13 104 105 106 107 a=rtpmap:9 G722/8000 a=rtpmap:102 G7221/32000 a=fmtp:102 bitrate=48000 a=rtpmap:103 G7221/16000 a=fmtp:103 bitrate=32000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtpmap:104 telephone-event/32000 a=fmtp:104 0-16 a=rtpmap:106 telephone-event/16000 a=fmtp:106 0-16 a=rtpmap:13 CN/8000 a=rtpmap:105 CN/32000 a=rtpmap:107 CN/16000 a=ptime:20 a=sendrecv send 1564 bytes to tcp/[172.23.3.30]:47079 at 12:44:36.315687: ------------------------------------------------------------------------ INVITE sip:Hawkeye@172.23.3.30;transport=tcp SIP/2.0 Via: SIP/2.0/TCP 10.66.77.88;rport;branch=z9hG4bKZmjDXFa2SKpFS Route: ;transport=tcp Max-Forwards: 69 From: "hulk" ;tag=cpmvXZtmmHmSe To: Call-ID: 04275acc-104d-1237-998e-00155dd37f11 CSeq: 126234874 INVITE Contact: User-Agent: FreeSWITCH 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: 574 X-FS-Support: update_display,send_info Remote-Party-ID: "hulk" ;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 1533119888 1533119889 IN IP4 10.66.77.88 s=FreeSWITCH c=IN IP4 10.66.77.88 t=0 0 m=audio 21988 RTP/AVP 9 102 103 0 8 101 13 104 105 106 107 a=rtpmap:9 G722/8000 a=rtpmap:102 G7221/32000 a=fmtp:102 bitrate=48000 a=rtpmap:103 G7221/16000 a=fmtp:103 bitrate=32000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtpmap:13 CN/8000 a=rtpmap:104 telephone-event/32000 a=fmtp:104 0-16 a=rtpmap:105 CN/32000 a=rtpmap:106 telephone-event/16000 a=fmtp:106 0-16 a=rtpmap:107 CN/16000 a=ptime:20 ------------------------------------------------------------------------ 2018-08-01 12:44:36.304635 [DEBUG] switch_core_state_machine.c:40 sofia/internal/Hawkeye@172.23.3.30 Standard INIT 2018-08-01 12:44:36.304635 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/Hawkeye@172.23.3.30) State Change CS_INIT -> CS_ROUTING 2018-08-01 12:44:36.304635 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/Hawkeye@172.23.3.30) State INIT going to sleep 2018-08-01 12:44:36.304635 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/Hawkeye@172.23.3.30) Running State Change CS_ROUTING (Cur 2 Tot 634) 2018-08-01 12:44:36.304635 [DEBUG] sofia.c:7084 Channel sofia/internal/Hawkeye@172.23.3.30 entering state [calling][0] 2018-08-01 12:44:36.304635 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/Hawkeye@172.23.3.30) State ROUTING 2018-08-01 12:44:36.304635 [DEBUG] mod_sofia.c:143 sofia/internal/Hawkeye@172.23.3.30 SOFIA ROUTING 2018-08-01 12:44:36.304635 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/Hawkeye@172.23.3.30) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2018-08-01 12:44:36.304635 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/Hawkeye@172.23.3.30) State ROUTING going to sleep 2018-08-01 12:44:36.304635 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/Hawkeye@172.23.3.30) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 634) 2018-08-01 12:44:36.304635 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/Hawkeye@172.23.3.30) State CONSUME_MEDIA 2018-08-01 12:44:36.304635 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/Hawkeye@172.23.3.30) State CONSUME_MEDIA going to sleep recv 438 bytes from tcp/[172.23.3.30]:47079 at 12:44:36.328034: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/TCP 10.66.77.88;rport;branch=z9hG4bKZmjDXFa2SKpFS From: "hulk" ;tag=cpmvXZtmmHmSe To: "Hawkeye" ;tag=98000888-4E200809 CSeq: 126234874 INVITE Call-ID: 04275acc-104d-1237-998e-00155dd37f11 Contact: User-Agent: PolycomVVX-VVX_310-UA/5.8.0.12848 Accept-Language: en Content-Length: 0 ------------------------------------------------------------------------ recv 475 bytes from tcp/[172.23.3.30]:47079 at 12:44:36.410237: ------------------------------------------------------------------------ SIP/2.0 180 Ringing Via: SIP/2.0/TCP 10.66.77.88;rport;branch=z9hG4bKZmjDXFa2SKpFS From: "hulk" ;tag=cpmvXZtmmHmSe To: "Hawkeye" ;tag=98000888-4E200809 CSeq: 126234874 INVITE Call-ID: 04275acc-104d-1237-998e-00155dd37f11 Contact: User-Agent: PolycomVVX-VVX_310-UA/5.8.0.12848 Allow-Events: conference,talk,hold Accept-Language: en Content-Length: 0 ------------------------------------------------------------------------ 2018-08-01 12:44:36.404633 [DEBUG] sofia.c:7084 Channel sofia/internal/Hawkeye@172.23.3.30 entering state [proceeding][180] 2018-08-01 12:44:36.404633 [NOTICE] sofia.c:7192 Ring-Ready sofia/internal/Hawkeye@172.23.3.30! 2018-08-01 12:44:36.404633 [DEBUG] switch_channel.c:3346 (sofia/internal/Hawkeye@172.23.3.30) Callstate Change DOWN -> RINGING 2018-08-01 12:44:36.404633 [INFO] switch_ivr_originate.c:1215 Sending early media 2018-08-01 12:44:36.404633 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/internal/hulk@avengers.fusion.pbx] 10.66.77.88 port 25390 -> 172.23.3.29 port 2234 codec: 9 ms: 20 2018-08-01 12:44:36.404633 [DEBUG] switch_rtp.c:4137 Starting timer [soft] 160 bytes per 20ms 2018-08-01 12:44:36.404633 [DEBUG] switch_core_media.c:7180 sofia/internal/hulk@avengers.fusion.pbx Set 2833 dtmf send payload to 127 2018-08-01 12:44:36.404633 [DEBUG] switch_core_media.c:7187 sofia/internal/hulk@avengers.fusion.pbx Set 2833 dtmf receive payload to 127 2018-08-01 12:44:36.404633 [DEBUG] switch_core_media.c:7210 sofia/internal/hulk@avengers.fusion.pbx Set rtp dtmf delay to 40 2018-08-01 12:44:36.404633 [DEBUG] mod_sofia.c:2364 Ring SDP: v=0 o=FreeSWITCH 1533116486 1533116487 IN IP4 10.66.77.88 s=FreeSWITCH c=IN IP4 10.66.77.88 t=0 0 m=audio 25390 RTP/AVP 9 127 a=rtpmap:9 G722/8000 a=rtpmap:127 telephone-event/8000 a=fmtp:127 0-16 a=ptime:20 a=sendrecv 2018-08-01 12:44:36.404633 [NOTICE] mod_sofia.c:2367 Pre-Answer sofia/internal/hulk@avengers.fusion.pbx! 2018-08-01 12:44:36.404633 [DEBUG] switch_channel.c:3474 (sofia/internal/hulk@avengers.fusion.pbx) Callstate Change RINGING -> EARLY send 1086 bytes to tcp/[172.23.3.29]:52335 at 12:44:36.420519: ------------------------------------------------------------------------ SIP/2.0 183 Session Progress Via: SIP/2.0/TCP 172.23.3.29;branch=z9hG4bKb0ee65b03D82E1D3;rport=52335 From: "hulk" ;tag=C072B00C-6643877F To: ;tag=BDU3U49gQ8X6j Call-ID: df58cf91afd08662d3aa437c04c34469 CSeq: 2 INVITE Contact: User-Agent: FreeSWITCH 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-Type: application/sdp Content-Disposition: session Content-Length: 222 Remote-Party-ID: "223" <223>;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1533116486 1533116487 IN IP4 10.66.77.88 s=FreeSWITCH c=IN IP4 10.66.77.88 t=0 0 m=audio 25390 RTP/AVP 9 127 a=rtpmap:9 G722/8000 a=rtpmap:127 telephone-event/8000 a=fmtp:127 0-16 a=ptime:20 ------------------------------------------------------------------------ 2018-08-01 12:44:36.404633 [DEBUG] sofia.c:7084 Channel sofia/internal/hulk@avengers.fusion.pbx entering state [early][183] 2018-08-01 12:44:36.404633 [DEBUG] switch_ivr_originate.c:1273 Raw Codec Activation Success L16@16000hz 1 channel 20ms 2018-08-01 12:44:36.404633 [DEBUG] switch_core_codec.c:223 sofia/internal/hulk@avengers.fusion.pbx Push codec L16:100 2018-08-01 12:44:36.404633 [DEBUG] switch_ivr_originate.c:1342 Play Ringback Tone [%(2000,4000,440,480)] 2018-08-01 12:44:36.564633 [DEBUG] switch_rtp.c:7308 Correct audio ip/port confirmed. recv 816 bytes from tcp/[172.23.3.29]:52335 at 12:44:37.360435: ------------------------------------------------------------------------ REGISTER sip:avengers.fusion.pbx;transport=tcp SIP/2.0 Via: SIP/2.0/TCP 172.23.3.29;branch=z9hG4bK16bcb794F732BB67 From: "hulk" ;tag=75A0856-8F6901C1 To: CSeq: 79 REGISTER Call-ID: c954e716b6287baec751d9f79fc34469 Contact: ;methods="INVITE,ACK,BYE,CANCEL,OPTIONS,INFO,MESSAGE,SUBSCRIBE,NOTIFY,PRACK,UPDATE,REFER" User-Agent: PolycomVVX-VVX_310-UA/5.8.0.12848 Accept-Language: en Authorization: Digest username="hulk", realm="avengers.fusion.pbx", nonce="6bb917ea-959f-11e8-b64a-815e756dd19a", qop=auth, cnonce="l8NmsPX56W3IGDF", nc=00000078, uri="sip:avengers.fusion.pbx;transport=tcp", response="30a75b42e4cd89c45fc0a95b43178b31", algorithm=MD5 Max-Forwards: 70 Expires: 120 Content-Length: 0 ------------------------------------------------------------------------ send 560 bytes to tcp/[172.23.3.29]:52335 at 12:44:37.369942: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TCP 172.23.3.29;branch=z9hG4bK16bcb794F732BB67;rport=52335 From: "hulk" ;tag=75A0856-8F6901C1 To: ;tag=DZDNZtBrHtaca Call-ID: c954e716b6287baec751d9f79fc34469 CSeq: 79 REGISTER Contact: ;expires=120 Date: Wed, 01 Aug 2018 16:44:37 GMT User-Agent: FreeSWITCH Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Content-Length: 0 ------------------------------------------------------------------------ recv 803 bytes from tcp/[172.23.3.30]:47079 at 12:44:38.654341: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TCP 10.66.77.88;rport;branch=z9hG4bKZmjDXFa2SKpFS From: "hulk" ;tag=cpmvXZtmmHmSe To: "Hawkeye" ;tag=98000888-4E200809 CSeq: 126234874 INVITE Call-ID: 04275acc-104d-1237-998e-00155dd37f11 Contact: Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,INFO,MESSAGE,SUBSCRIBE,NOTIFY,PRACK,UPDATE,REFER Supported: replaces,100rel User-Agent: PolycomVVX-VVX_310-UA/5.8.0.12848 Allow-Events: conference,talk,hold Accept-Language: en Content-Type: application/sdp Content-Length: 185 v=0 o=- 1533141880 1533141880 IN IP4 172.23.3.30 s=Polycom IP Phone c=IN IP4 172.23.3.30 t=0 0 m=audio 2232 RTP/AVP 9 101 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 ------------------------------------------------------------------------ 2018-08-01 12:44:38.644639 [DEBUG] sofia.c:7084 Channel sofia/internal/Hawkeye@172.23.3.30 entering state [completing][200] 2018-08-01 12:44:38.644639 [DEBUG] sofia.c:7094 Remote SDP: v=0 o=- 1533141880 1533141880 IN IP4 172.23.3.30 s=Polycom IP Phone c=IN IP4 172.23.3.30 t=0 0 m=audio 2232 RTP/AVP 9 101 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 send 415 bytes to tcp/[172.23.3.30]:47079 at 12:44:38.655999: ------------------------------------------------------------------------ ACK sip:Hawkeye@172.23.3.30;transport=tcp SIP/2.0 Via: SIP/2.0/TCP 10.66.77.88;rport;branch=z9hG4bK0XB6yaU5pvc2m Max-Forwards: 70 From: "hulk" ;tag=cpmvXZtmmHmSe To: ;tag=98000888-4E200809 Call-ID: 04275acc-104d-1237-998e-00155dd37f11 CSeq: 126234874 ACK Contact: Content-Length: 0 ------------------------------------------------------------------------ 2018-08-01 12:44:38.644639 [DEBUG] sofia.c:7084 Channel sofia/internal/Hawkeye@172.23.3.30 entering state [ready][200] 2018-08-01 12:44:38.644639 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2018-08-01 12:44:38.644639 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match 2018-08-01 12:44:38.644639 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[G7221:115:32000:20:48000:1] 2018-08-01 12:44:38.644639 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[G7221:107:16000:20:32000:1] 2018-08-01 12:44:38.644639 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2018-08-01 12:44:38.644639 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2018-08-01 12:44:38.644639 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000 2018-08-01 12:44:38.644639 [DEBUG] switch_core_media.c:3061 Set Codec sofia/internal/Hawkeye@172.23.3.30 G722/8000 20 ms 160 samples 64000 bits 1 channels 2018-08-01 12:44:38.644639 [DEBUG] switch_core_codec.c:111 sofia/internal/Hawkeye@172.23.3.30 Original read codec set to G722:9 2018-08-01 12:44:38.644639 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000 2018-08-01 12:44:38.644639 [DEBUG] switch_core_media.c:4767 sofia/internal/Hawkeye@172.23.3.30 Set 2833 dtmf send payload to 101 recv payload to 101 2018-08-01 12:44:38.644639 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/internal/Hawkeye@172.23.3.30] 10.66.77.88 port 21988 -> 172.23.3.30 port 2232 codec: 9 ms: 20 2018-08-01 12:44:38.644639 [DEBUG] switch_rtp.c:4137 Starting timer [soft] 160 bytes per 20ms 2018-08-01 12:44:38.644639 [DEBUG] switch_core_media.c:7180 sofia/internal/Hawkeye@172.23.3.30 Set 2833 dtmf send payload to 101 2018-08-01 12:44:38.644639 [DEBUG] switch_core_media.c:7187 sofia/internal/Hawkeye@172.23.3.30 Set 2833 dtmf receive payload to 101 2018-08-01 12:44:38.644639 [DEBUG] switch_core_media.c:7210 sofia/internal/Hawkeye@172.23.3.30 Set rtp dtmf delay to 40 2018-08-01 12:44:38.644639 [NOTICE] sofia.c:8218 Channel [sofia/internal/Hawkeye@172.23.3.30] has been answered 2018-08-01 12:44:38.644639 [DEBUG] switch_channel.c:3773 (sofia/internal/Hawkeye@172.23.3.30) Callstate Change RINGING -> ACTIVE 2018-08-01 12:44:38.644639 [DEBUG] switch_core_codec.c:248 sofia/internal/hulk@avengers.fusion.pbx Restore previous codec G722:9. 2018-08-01 12:44:38.644639 [DEBUG] switch_core_media.c:6861 Audio params are unchanged for sofia/internal/hulk@avengers.fusion.pbx. 2018-08-01 12:44:38.644639 [DEBUG] mod_sofia.c:850 Local SDP sofia/internal/hulk@avengers.fusion.pbx: v=0 o=FreeSWITCH 1533116486 1533116488 IN IP4 10.66.77.88 s=FreeSWITCH c=IN IP4 10.66.77.88 t=0 0 m=audio 25390 RTP/AVP 9 127 a=rtpmap:9 G722/8000 a=rtpmap:127 telephone-event/8000 a=fmtp:127 0-16 a=ptime:20 a=sendrecv send 1051 bytes to tcp/[172.23.3.29]:52335 at 12:44:38.660295: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TCP 172.23.3.29;branch=z9hG4bKb0ee65b03D82E1D3;rport=52335 From: "hulk" ;tag=C072B00C-6643877F To: ;tag=BDU3U49gQ8X6j Call-ID: df58cf91afd08662d3aa437c04c34469 CSeq: 2 INVITE Contact: User-Agent: FreeSWITCH 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: 222 Remote-Party-ID: "223" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1533116486 1533116487 IN IP4 10.66.77.88 s=FreeSWITCH c=IN IP4 10.66.77.88 t=0 0 m=audio 25390 RTP/AVP 9 127 a=rtpmap:9 G722/8000 a=rtpmap:127 telephone-event/8000 a=fmtp:127 0-16 a=ptime:20 ------------------------------------------------------------------------ 2018-08-01 12:44:38.644639 [DEBUG] sofia.c:7084 Channel sofia/internal/hulk@avengers.fusion.pbx entering state [completed][200] 2018-08-01 12:44:38.644639 [NOTICE] switch_ivr_originate.c:3647 Channel [sofia/internal/hulk@avengers.fusion.pbx] has been answered 2018-08-01 12:44:38.644639 [DEBUG] switch_channel.c:3773 (sofia/internal/hulk@avengers.fusion.pbx) Callstate Change EARLY -> ACTIVE 2018-08-01 12:44:38.644639 [DEBUG] switch_ivr_originate.c:3705 Originate Resulted in Success: [sofia/internal/Hawkeye@172.23.3.30] 2018-08-01 12:44:38.644639 [DEBUG] switch_ivr_originate.c:3705 Originate Resulted in Success: [sofia/internal/Hawkeye@172.23.3.30] 2018-08-01 12:44:38.644639 [DEBUG] switch_ivr_bridge.c:1614 (sofia/internal/Hawkeye@172.23.3.30) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2018-08-01 12:44:38.644639 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/Hawkeye@172.23.3.30) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 634) 2018-08-01 12:44:38.644639 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/Hawkeye@172.23.3.30) State EXCHANGE_MEDIA 2018-08-01 12:44:38.644639 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA recv 547 bytes from tcp/[172.23.3.29]:52335 at 12:44:38.671204: ------------------------------------------------------------------------ ACK sip:223@10.66.77.88:5060;transport=tcp SIP/2.0 Via: SIP/2.0/TCP 172.23.3.29;branch=z9hG4bK9c2ffbdeF79631A9 From: "hulk" ;tag=C072B00C-6643877F To: ;tag=BDU3U49gQ8X6j CSeq: 2 ACK Call-ID: df58cf91afd08662d3aa437c04c34469 Contact: Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,INFO,MESSAGE,SUBSCRIBE,NOTIFY,PRACK,UPDATE,REFER User-Agent: PolycomVVX-VVX_310-UA/5.8.0.12848 Accept-Language: en Max-Forwards: 70 Content-Length: 0 ------------------------------------------------------------------------ 2018-08-01 12:44:38.664631 [DEBUG] sofia.c:7084 Channel sofia/internal/hulk@avengers.fusion.pbx entering state [ready][200] send 1262 bytes to tcp/[172.23.3.30]:47079 at 12:44:38.696770: ------------------------------------------------------------------------ UPDATE sip:Hawkeye@172.23.3.30;transport=tcp SIP/2.0 Via: SIP/2.0/TCP 10.66.77.88;rport;branch=z9hG4bK164y05B9K52mg Max-Forwards: 70 From: "hulk" ;tag=cpmvXZtmmHmSe To: ;tag=98000888-4E200809 Call-ID: 04275acc-104d-1237-998e-00155dd37f11 CSeq: 126234875 UPDATE Contact: User-Agent: FreeSWITCH Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Content-Type: application/sdp Content-Disposition: session Content-Length: 574 P-Asserted-Identity: "hulk" v=0 o=FreeSWITCH 1533119888 1533119889 IN IP4 10.66.77.88 s=FreeSWITCH c=IN IP4 10.66.77.88 t=0 0 m=audio 21988 RTP/AVP 9 101 102 103 0 8 13 104 105 106 107 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtpmap:102 G7221/32000 a=fmtp:102 bitrate=48000 a=rtpmap:103 G7221/16000 a=fmtp:103 bitrate=32000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:13 CN/8000 a=rtpmap:104 telephone-event/32000 a=fmtp:104 0-16 a=rtpmap:105 CN/32000 a=rtpmap:106 telephone-event/16000 a=fmtp:106 0-16 a=rtpmap:107 CN/16000 a=ptime:20 ------------------------------------------------------------------------ 2018-08-01 12:44:38.684639 [DEBUG] sofia.c:7084 Channel sofia/internal/Hawkeye@172.23.3.30 entering state [calling][0] send 902 bytes to tcp/[172.23.3.29]:5060 at 12:44:38.698428: ------------------------------------------------------------------------ UPDATE sip:hulk@172.23.3.29;transport=tcp SIP/2.0 Via: SIP/2.0/TCP 10.66.77.88;rport;branch=z9hG4bK2FyQ20vcHeS7B Max-Forwards: 70 From: ;tag=BDU3U49gQ8X6j To: "hulk" ;tag=C072B00C-6643877F Call-ID: df58cf91afd08662d3aa437c04c34469 CSeq: 126234875 UPDATE Contact: User-Agent: FreeSWITCH Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Content-Type: application/sdp Content-Disposition: session Content-Length: 222 P-Asserted-Identity: "223" v=0 o=FreeSWITCH 1533116486 1533116487 IN IP4 10.66.77.88 s=FreeSWITCH c=IN IP4 10.66.77.88 t=0 0 m=audio 25390 RTP/AVP 9 127 a=rtpmap:9 G722/8000 a=rtpmap:127 telephone-event/8000 a=fmtp:127 0-16 a=ptime:20 ------------------------------------------------------------------------ 2018-08-01 12:44:38.684639 [DEBUG] sofia.c:7084 Channel sofia/internal/hulk@avengers.fusion.pbx entering state [calling][0] 2018-08-01 12:44:38.704649 [DEBUG] switch_rtp.c:7308 Correct audio ip/port confirmed. recv 652 bytes from tcp/[172.23.3.30]:47079 at 12:44:38.748280: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TCP 10.66.77.88;rport;branch=z9hG4bK164y05B9K52mg From: "hulk" ;tag=cpmvXZtmmHmSe To: "Hawkeye" ;tag=98000888-4E200809 CSeq: 126234875 UPDATE Call-ID: 04275acc-104d-1237-998e-00155dd37f11 Contact: User-Agent: PolycomVVX-VVX_310-UA/5.8.0.12848 Accept-Language: en Content-Type: application/sdp Content-Length: 185 v=0 o=- 1533141880 1533141880 IN IP4 172.23.3.30 s=Polycom IP Phone c=IN IP4 172.23.3.30 t=0 0 m=audio 2232 RTP/AVP 9 101 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 ------------------------------------------------------------------------ 2018-08-01 12:44:38.744641 [DEBUG] sofia.c:7084 Channel sofia/internal/Hawkeye@172.23.3.30 entering state [ready][200] 2018-08-01 12:44:38.744641 [DEBUG] sofia.c:7091 Duplicate SDP v=0 o=- 1533141880 1533141880 IN IP4 172.23.3.30 s=Polycom IP Phone c=IN IP4 172.23.3.30 t=0 0 m=audio 2232 RTP/AVP 9 101 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 2018-08-01 12:44:38.744641 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2018-08-01 12:44:38.744641 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match 2018-08-01 12:44:38.744641 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[G7221:115:32000:20:48000:1] 2018-08-01 12:44:38.744641 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[G7221:107:16000:20:32000:1] 2018-08-01 12:44:38.744641 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2018-08-01 12:44:38.744641 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2018-08-01 12:44:38.744641 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000 2018-08-01 12:44:38.744641 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000 2018-08-01 12:44:38.744641 [DEBUG] switch_core_media.c:4767 sofia/internal/Hawkeye@172.23.3.30 Set 2833 dtmf send payload to 101 recv payload to 101 2018-08-01 12:44:38.744641 [DEBUG] sofia.c:8061 Processing updated SDP 2018-08-01 12:44:38.744641 [DEBUG] switch_core_media.c:6861 Audio params are unchanged for sofia/internal/Hawkeye@172.23.3.30. 2018-08-01 12:44:38.784719 [DEBUG] switch_rtp.c:7308 Correct audio ip/port confirmed. 2018-08-01 12:44:40.544771 [NOTICE] sofia_reg.c:448 Registering 0b6a6aab-f5eb-4091-af69-3437de4db44a 2018-08-01 12:44:40.544771 [ERR] sofia_reg.c:2447 0b6a6aab-f5eb-4091-af69-3437de4db44a Failed Registration with status DNS Error [503]. failure #8465 2018-08-01 12:44:41.544704 [WARNING] sofia_reg.c:505 0b6a6aab-f5eb-4091-af69-3437de4db44a Failed Registration [503], setting retry to 30 seconds. recv 801 bytes from tcp/[172.23.3.29]:5060 at 12:44:44.213927: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TCP 10.66.77.88;rport;branch=z9hG4bKvS62QyQQ2rKQp From: ;tag=Z0Bt6ZZ6SXj6Q To: "hulk" ;tag=528A10A0-2D0B6C03 CSeq: 126234824 UPDATE Call-ID: 281a66cdc0b197cabdf781e883c34469 Contact: User-Agent: PolycomVVX-VVX_310-UA/5.8.0.12848 Accept-Language: en Content-Type: application/sdp Content-Length: 348 v=0 o=- 1533141775 1533141775 IN IP4 172.23.3.29 s=Polycom IP Phone c=IN IP4 172.23.3.29 t=0 0 a=sendrecv m=audio 2232 RTP/AVP 9 102 0 8 18 127 a=rtpmap:9 G722/8000 a=rtpmap:102 G7221/16000 a=fmtp:102 bitrate=32000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:127 telephone-event/8000 ------------------------------------------------------------------------ 2018-08-01 12:44:45.104728 [DEBUG] sofia_reg.c:2435 Changing expire time to 51 by request of proxy sip:sip.myswitch recv 846 bytes from tcp/[321.44.55.66]:61610 at 12:44:53.694180: ------------------------------------------------------------------------ REGISTER sip:avengers.fusion.pbx;transport=tcp SIP/2.0 Via: SIP/2.0/TCP 192.168.0.114;branch=z9hG4bKa7073e1bD08C3B7C From: "Spiderman" ;tag=B0840DB9-488ECE22 To: CSeq: 79 REGISTER Call-ID: f77a9996686cccb3a590d0a1a2c34514 Contact: ;methods="INVITE,ACK,BYE,CANCEL,OPTIONS,INFO,MESSAGE,SUBSCRIBE,NOTIFY,PRACK,UPDATE,REFER" User-Agent: PolycomVVX-VVX_310-UA/5.8.0.12848 Accept-Language: en Authorization: Digest username="Spiderman", realm="avengers.fusion.pbx", nonce="7572f04e-959f-11e8-b64b-815e756dd19a", qop=auth, cnonce="BE77lqY52NypVtb", nc=00000078, uri="sip:avengers.fusion.pbx;transport=tcp", response="d0d3b9725ac5b14b2de373f92b1de318", algorithm=MD5 Max-Forwards: 70 Expires: 120 Content-Length: 0 ------------------------------------------------------------------------ send 608 bytes to tcp/[321.44.55.66]:61610 at 12:44:53.704690: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TCP 192.168.0.114;branch=z9hG4bKa7073e1bD08C3B7C;received=321.44.55.66;rport=61610 From: "Spiderman" ;tag=B0840DB9-488ECE22 To: ;tag=e86D1NvUe30yN Call-ID: f77a9996686cccb3a590d0a1a2c34514 CSeq: 79 REGISTER Contact: ;expires=120 Date: Wed, 01 Aug 2018 16:44:53 GMT User-Agent: FreeSWITCH Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Content-Length: 0 ------------------------------------------------------------------------ recv 836 bytes from tcp/[321.44.55.66]:60653 at 12:45:08.809741: ------------------------------------------------------------------------ REGISTER sip:avengers.fusion.pbx;transport=tcp SIP/2.0 Via: SIP/2.0/TCP 192.168.0.112;branch=z9hG4bK99e93e423C3C93BB From: "Ironman" ;tag=6DDB714C-9A67E675 To: CSeq: 79 REGISTER Call-ID: 6accbd6d727f6e05777aa0d3a7c34396 Contact: ;methods="INVITE,ACK,BYE,CANCEL,OPTIONS,INFO,MESSAGE,SUBSCRIBE,NOTIFY,PRACK,UPDATE,REFER" User-Agent: PolycomVVX-VVX_310-UA/5.8.0.12848 Accept-Language: en Authorization: Digest username="Ironman", realm="avengers.fusion.pbx", nonce="7e79be8e-959f-11e8-b64c-815e756dd19a", qop=auth, cnonce="IMNIcf2gmniF6xv", nc=00000078, uri="sip:avengers.fusion.pbx;transport=tcp", response="712488264bcba07f30ba29ca4a58c911", algorithm=MD5 Max-Forwards: 70 Expires: 120 Content-Length: 0 ------------------------------------------------------------------------ send 600 bytes to tcp/[321.44.55.66]:60653 at 12:45:08.822233: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TCP 192.168.0.112;branch=z9hG4bK99e93e423C3C93BB;received=321.44.55.66;rport=60653 From: "Ironman" ;tag=6DDB714C-9A67E675 To: ;tag=FH062gDZBcQHH Call-ID: 6accbd6d727f6e05777aa0d3a7c34396 CSeq: 79 REGISTER Contact: ;expires=120 Date: Wed, 01 Aug 2018 16:45:08 GMT User-Agent: FreeSWITCH Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Content-Length: 0 ------------------------------------------------------------------------ 2018-08-01 12:45:09.104674 [DEBUG] sofia_reg.c:2435 Changing expire time to 59 by request of proxy sip:sip.myswitch send 573 bytes to tcp/[172.23.3.29]:5060 at 12:45:10.697989: ------------------------------------------------------------------------ BYE sip:hulk@172.23.3.29;transport=tcp SIP/2.0 Via: SIP/2.0/TCP 10.66.77.88;rport;branch=z9hG4bK3rQg4UDgeQFtQ Max-Forwards: 70 From: ;tag=BDU3U49gQ8X6j To: "hulk" ;tag=C072B00C-6643877F Call-ID: df58cf91afd08662d3aa437c04c34469 CSeq: 126234876 BYE Contact: User-Agent: FreeSWITCH Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Content-Length: 0 ------------------------------------------------------------------------ 2018-08-01 12:45:10.684638 [DEBUG] sofia.c:7084 Channel sofia/internal/hulk@avengers.fusion.pbx entering state [terminating][487] 2018-08-01 12:45:10.684638 [NOTICE] sofia.c:8273 Hangup sofia/internal/hulk@avengers.fusion.pbx [CS_EXECUTE] [ORIGINATOR_CANCEL] 2018-08-01 12:45:10.684638 [DEBUG] mod_hash.c:297 Usage for avengers.fusion.pbx_223 is now 0 2018-08-01 12:45:10.684638 [DEBUG] switch_ivr_bridge.c:712 sofia/internal/hulk@avengers.fusion.pbx ending bridge by request from read function 2018-08-01 12:45:10.684638 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/internal/hulk@avengers.fusion.pbx] 2018-08-01 12:45:10.704641 [DEBUG] switch_ivr_bridge.c:706 sofia/internal/hulk@avengers.fusion.pbx ending bridge by request from write function 2018-08-01 12:45:10.704641 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/internal/Hawkeye@172.23.3.30] 2018-08-01 12:45:10.704641 [NOTICE] switch_ivr_bridge.c:904 Hangup sofia/internal/Hawkeye@172.23.3.30 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] 2018-08-01 12:45:10.704641 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/Hawkeye@172.23.3.30) State EXCHANGE_MEDIA going to sleep 2018-08-01 12:45:10.704641 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/Hawkeye@172.23.3.30) Running State Change CS_HANGUP (Cur 2 Tot 634) 2018-08-01 12:45:10.704641 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/Hawkeye@172.23.3.30) Callstate Change ACTIVE -> HANGUP 2018-08-01 12:45:10.704641 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/Hawkeye@172.23.3.30) State HANGUP 2018-08-01 12:45:10.704641 [DEBUG] mod_sofia.c:432 sofia/internal/Hawkeye@172.23.3.30 Overriding SIP cause 480 with 487 from the other leg 2018-08-01 12:45:10.704641 [DEBUG] mod_sofia.c:438 Channel sofia/internal/Hawkeye@172.23.3.30 hanging up, cause: NORMAL_CLEARING 2018-08-01 12:45:10.704641 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/internal/Hawkeye@172.23.3.30 send 571 bytes to tcp/[172.23.3.30]:47079 at 12:45:10.718084: ------------------------------------------------------------------------ BYE sip:Hawkeye@172.23.3.30;transport=tcp SIP/2.0 Via: SIP/2.0/TCP 10.66.77.88;rport;branch=z9hG4bK41g95pyKB05cK Max-Forwards: 70 From: "hulk" ;tag=cpmvXZtmmHmSe To: ;tag=98000888-4E200809 Call-ID: 04275acc-104d-1237-998e-00155dd37f11 CSeq: 126234876 BYE User-Agent: FreeSWITCH 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 ------------------------------------------------------------------------ 2018-08-01 12:45:10.704641 [DEBUG] switch_core_state_machine.c:60 sofia/internal/Hawkeye@172.23.3.30 Standard HANGUP, cause: NORMAL_CLEARING 2018-08-01 12:45:10.704641 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/Hawkeye@172.23.3.30) State HANGUP going to sleep 2018-08-01 12:45:10.704641 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/Hawkeye@172.23.3.30) State Change CS_HANGUP -> CS_REPORTING 2018-08-01 12:45:10.704641 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/Hawkeye@172.23.3.30) Running State Change CS_REPORTING (Cur 2 Tot 634) 2018-08-01 12:45:10.704641 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/Hawkeye@172.23.3.30) State REPORTING 2018-08-01 12:45:10.704641 [DEBUG] switch_core_state_machine.c:174 sofia/internal/Hawkeye@172.23.3.30 Standard REPORTING, cause: NORMAL_CLEARING 2018-08-01 12:45:10.704641 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/Hawkeye@172.23.3.30) State REPORTING going to sleep 2018-08-01 12:45:10.704641 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/Hawkeye@172.23.3.30) State Change CS_REPORTING -> CS_DESTROY 2018-08-01 12:45:10.704641 [DEBUG] switch_core_session.c:1665 Session 634 (sofia/internal/Hawkeye@172.23.3.30) Locked, Waiting on external entities 2018-08-01 12:45:10.704641 [DEBUG] switch_ivr_bridge.c:1715 sofia/internal/hulk@avengers.fusion.pbx skip receive message [UNBRIDGE] (channel is hungup already) 2018-08-01 12:45:10.704641 [DEBUG] switch_core_session.c:2815 sofia/internal/hulk@avengers.fusion.pbx skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2018-08-01 12:45:10.704641 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/hulk@avengers.fusion.pbx) State EXECUTE going to sleep 2018-08-01 12:45:10.704641 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/hulk@avengers.fusion.pbx) Running State Change CS_HANGUP (Cur 2 Tot 634) 2018-08-01 12:45:10.704641 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/hulk@avengers.fusion.pbx) Callstate Change ACTIVE -> HANGUP 2018-08-01 12:45:10.704641 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/hulk@avengers.fusion.pbx) State HANGUP 2018-08-01 12:45:10.704641 [DEBUG] mod_sofia.c:438 Channel sofia/internal/hulk@avengers.fusion.pbx hanging up, cause: ORIGINATOR_CANCEL 2018-08-01 12:45:10.704641 [DEBUG] switch_core_state_machine.c:60 sofia/internal/hulk@avengers.fusion.pbx Standard HANGUP, cause: ORIGINATOR_CANCEL 2018-08-01 12:45:10.704641 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/hulk@avengers.fusion.pbx) State HANGUP going to sleep 2018-08-01 12:45:10.704641 [DEBUG] switch_core_state_machine.c:783 Hangup Command with no Session lua(app.lua hangup): 2018-08-01 12:45:10.704641 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/hulk@avengers.fusion.pbx) State Change CS_HANGUP -> CS_REPORTING 2018-08-01 12:45:10.724663 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/hulk@avengers.fusion.pbx) Running State Change CS_REPORTING (Cur 2 Tot 634) 2018-08-01 12:45:10.724663 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/hulk@avengers.fusion.pbx) State REPORTING 2018-08-01 12:45:10.724663 [NOTICE] switch_core_session.c:1683 Session 634 (sofia/internal/Hawkeye@172.23.3.30) Ended 2018-08-01 12:45:10.724663 [NOTICE] switch_core_session.c:1687 Close Channel sofia/internal/Hawkeye@172.23.3.30 [CS_DESTROY] 2018-08-01 12:45:10.724663 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/Hawkeye@172.23.3.30) Running State Change CS_DESTROY (Cur 1 Tot 634) 2018-08-01 12:45:10.724663 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/Hawkeye@172.23.3.30) State DESTROY 2018-08-01 12:45:10.724663 [DEBUG] mod_sofia.c:343 sofia/internal/Hawkeye@172.23.3.30 SOFIA DESTROY 2018-08-01 12:45:10.724663 [DEBUG] switch_core_state_machine.c:181 sofia/internal/Hawkeye@172.23.3.30 Standard DESTROY 2018-08-01 12:45:10.724663 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/Hawkeye@172.23.3.30) State DESTROY going to sleep recv 431 bytes from tcp/[172.23.3.30]:47079 at 12:45:10.727291: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TCP 10.66.77.88;rport;branch=z9hG4bK41g95pyKB05cK From: "hulk" ;tag=cpmvXZtmmHmSe To: "Hawkeye" ;tag=98000888-4E200809 CSeq: 126234876 BYE Call-ID: 04275acc-104d-1237-998e-00155dd37f11 Contact: User-Agent: PolycomVVX-VVX_310-UA/5.8.0.12848 Accept-Language: en Content-Length: 0 ------------------------------------------------------------------------ 2018-08-01 12:45:10.764635 [DEBUG] switch_core_state_machine.c:174 sofia/internal/hulk@avengers.fusion.pbx Standard REPORTING, cause: ORIGINATOR_CANCEL 2018-08-01 12:45:10.764635 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/hulk@avengers.fusion.pbx) State REPORTING going to sleep 2018-08-01 12:45:10.764635 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/hulk@avengers.fusion.pbx) State Change CS_REPORTING -> CS_DESTROY 2018-08-01 12:45:10.764635 [DEBUG] switch_core_session.c:1665 Session 633 (sofia/internal/hulk@avengers.fusion.pbx) Locked, Waiting on external entities 2018-08-01 12:45:10.764635 [NOTICE] switch_core_session.c:1683 Session 633 (sofia/internal/hulk@avengers.fusion.pbx) Ended 2018-08-01 12:45:10.764635 [NOTICE] switch_core_session.c:1687 Close Channel sofia/internal/hulk@avengers.fusion.pbx [CS_DESTROY] 2018-08-01 12:45:10.764635 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/hulk@avengers.fusion.pbx) Running State Change CS_DESTROY (Cur 0 Tot 634) 2018-08-01 12:45:10.764635 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/hulk@avengers.fusion.pbx) State DESTROY 2018-08-01 12:45:10.764635 [DEBUG] mod_sofia.c:343 sofia/internal/hulk@avengers.fusion.pbx SOFIA DESTROY 2018-08-01 12:45:10.764635 [DEBUG] switch_core_state_machine.c:181 sofia/internal/hulk@avengers.fusion.pbx Standard DESTROY 2018-08-01 12:45:10.764635 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/hulk@avengers.fusion.pbx) State DESTROY going to sleep 2018-08-01 12:45:12.644640 [NOTICE] sofia_reg.c:448 Registering 0b6a6aab-f5eb-4091-af69-3437de4db44a 2018-08-01 12:45:12.644640 [ERR] sofia_reg.c:2447 0b6a6aab-f5eb-4091-af69-3437de4db44a Failed Registration with status DNS Error [503]. failure #8466 2018-08-01 12:45:13.664642 [WARNING] sofia_reg.c:505 0b6a6aab-f5eb-4091-af69-3437de4db44a Failed Registration [503], setting retry to 30 seconds. recv 872 bytes from tcp/[172.23.3.32]:39378 at 12:45:27.852506: ------------------------------------------------------------------------ REGISTER sip:avengers.fusion.pbx;transport=tcp SIP/2.0 Via: SIP/2.0/TCP 172.23.3.32;branch=z9hG4bKafa8dfffC53723AE From: "Captain-America" ;tag=F045F51F-F4798FCE To: CSeq: 80 REGISTER Call-ID: 0c0220d59edfd1f9be851131fac348ad Contact: ;methods="INVITE,ACK,BYE,CANCEL,OPTIONS,INFO,MESSAGE,SUBSCRIBE,NOTIFY,PRACK,UPDATE,REFER" User-Agent: PolycomVVX-VVX_310-UA/5.8.0.12848 Accept-Language: en Authorization: Digest username="Captain-America", realm="avengers.fusion.pbx", nonce="660ea544-959f-11e8-b648-815e756dd19a", qop=auth, cnonce="hrmO5i0K5Y2WSki", nc=00000079, uri="sip:avengers.fusion.pbx;transport=tcp", response="250ac2432b24d9ff9a86e1117540e065", algorithm=MD5 Max-Forwards: 70 Expires: 120 Content-Length: 0 ------------------------------------------------------------------------ send 605 bytes to tcp/[172.23.3.32]:39378 at 12:45:27.865989: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TCP 172.23.3.32;branch=z9hG4bKafa8dfffC53723AE;rport=39378 From: "Captain-America" ;tag=F045F51F-F4798FCE To: ;tag=H3jr66e65X3pr Call-ID: 0c0220d59edfd1f9be851131fac348ad CSeq: 80 REGISTER Contact: ;expires=120 Date: Wed, 01 Aug 2018 16:45:27 GMT User-Agent: FreeSWITCH Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Content-Length: 0 ------------------------------------------------------------------------ 2018-08-01 12:45:28.104667 [DEBUG] sofia_reg.c:2435 Changing expire time to 52 by request of proxy sip:sip.myswitch recv 832 bytes from tcp/[172.23.3.30]:47079 at 12:45:28.397477: ------------------------------------------------------------------------ REGISTER sip:avengers.fusion.pbx;transport=tcp SIP/2.0 Via: SIP/2.0/TCP 172.23.3.30;branch=z9hG4bK5a5509fa123D7F5B From: "Hawkeye" ;tag=8E3C5D12-B6DC9CF3 To: CSeq: 80 REGISTER Call-ID: c3465afe677dbecc87856f5959c3449e Contact: ;methods="INVITE,ACK,BYE,CANCEL,OPTIONS,INFO,MESSAGE,SUBSCRIBE,NOTIFY,PRACK,UPDATE,REFER" User-Agent: PolycomVVX-VVX_310-UA/5.8.0.12848 Accept-Language: en Authorization: Digest username="Hawkeye", realm="avengers.fusion.pbx", nonce="66649224-959f-11e8-b649-815e756dd19a", qop=auth, cnonce="hrmO5i0K5Y2WSki", nc=00000079, uri="sip:avengers.fusion.pbx;transport=tcp", response="bb6b66e12d80473535ac22ad02b27365", algorithm=MD5 Max-Forwards: 70 Expires: 120 Content-Length: 0 ------------------------------------------------------------------------ send 573 bytes to tcp/[172.23.3.30]:47079 at 12:45:28.412130: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TCP 172.23.3.30;branch=z9hG4bK5a5509fa123D7F5B;rport=47079 From: "Hawkeye" ;tag=8E3C5D12-B6DC9CF3 To: ;tag=jccH81Z926S9K Call-ID: c3465afe677dbecc87856f5959c3449e CSeq: 80 REGISTER Contact: ;expires=120 Date: Wed, 01 Aug 2018 16:45:28 GMT User-Agent: FreeSWITCH Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Content-Length: 0 ------------------------------------------------------------------------ freeswitch@fusion.pbx> sofia profile internal siptrace off Disabled sip debugging on internal