From Voluminous Panda, 8 Years ago, written in FreeSWITCH.
This paste is a reply to Untitled from Brent
- go back
Embed
Viewing differences between Untitled and Re: Untitled
+OK log level  [7]
freeswitch@internal> sofia global siptrace on
+OK Global siptrace on
recv 1188 bytes from udp/[64.7.96.3]:5060 at 03:05:04.499268:
   ------------------------------------------------------------------------
   INVITE sip:6303437370@64.7.99.27:5080 SIP/2.0
   Record-Route: <sip:64.7.96.3;lr=on;ftag=eea75a70-f420-4416-8968-d6e5dfadb3f4-30174388;mp=yes;vsf=AAAAAAEACAB4AQYeDh55ABoYNy45Ni4z>
   Via: SIP/2.0/UDP 64.7.96.3;branch=z9hG4bKfe59.feb100c6.0
   Via: SIP/2.0/UDP 64.7.96.6:5060;branch=z9hG4bK194a11786434f
   From: "Brent Sachnoff" <sip:7086872090@64.7.96.3>;tag=eea75a70-f420-4416-8968-d6e5dfadb3f4-30174388
   To: <sip:16303437370@64.7.96.3>
   Date: Wed, 11 May 2016 08:05:04 GMT
   Call-ID: ffe3d80-7321e7b0-bfc3-6600740@64.7.96.6
   Supported: timer,replaces
   Min-SE:  1800
   User-Agent: Cisco-CCM5.1
   Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY
   CSeq: 101 INVITE
   Contact: <sip:6006@64.7.96.6:5060>
   Expires: 180
   Allow-Events: presence, kpml
   Call-Info: <sip:64.7.96.6:5060>;method="NOTIFY;Event=telephone-event;Duration=500"
   Session-Expires:  1800
   Max-Forwards: 69
   Content-Type: application/sdp
   Content-Length: 206
   P-hint: mediaproxy applied
   
   v=0
   o=CiscoSystemsCCM-SIP 2000 1 IN IP4 64.7.96.6
   s=SIP Call
   c=IN IP4 64.7.96.3
   t=0 0
   m=audio 44250 RTP/AVP 0 101
   a=rtpmap:0 PCMU/8000
   a=ptime:20
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-15
   ------------------------------------------------------------------------
send 518 bytes to udp/[64.7.96.3]:5060 at 03:05:04.499627:
   ------------------------------------------------------------------------
   SIP/2.0 100 Trying
   Via: SIP/2.0/UDP 64.7.96.3;branch=z9hG4bKfe59.feb100c6.0
   Via: SIP/2.0/UDP 64.7.96.6:5060;branch=z9hG4bK194a11786434f
   Record-Route: <sip:64.7.96.3;lr=on;ftag=eea75a70-f420-4416-8968-d6e5dfadb3f4-30174388;mp=yes;vsf=AAAAAAEACAB4AQYeDh55ABoYNy45Ni4z>
   From: "Brent Sachnoff" <sip:7086872090@64.7.96.3>;tag=eea75a70-f420-4416-8968-d6e5dfadb3f4-30174388
   To: <sip:16303437370@64.7.96.3>
   Call-ID: ffe3d80-7321e7b0-bfc3-6600740@64.7.96.6
   CSeq: 101 INVITE
   User-Agent: FreeSWITCH
   Content-Length: 0
   
   ------------------------------------------------------------------------
2016-05-11 03:05:04.480940 [NOTICE] switch_channel.c:1101 New Channel sofia/external/7086872090@64.7.96.3 [11828066-174f-11e6-b94d-8dcc9e1d3d65]
2016-05-11 03:05:04.480940 [DEBUG] switch_core_state_machine.c:473 (sofia/external/7086872090@64.7.96.3) Running State Change CS_NEW
2016-05-11 03:05:04.480940 [DEBUG] sofia.c:9248 sofia/external/7086872090@64.7.96.3 receiving invite from 64.7.96.3:5060 version: 1.6.6  64bit
2016-05-11 03:05:04.480940 [DEBUG] sofia.c:6760 Channel sofia/external/7086872090@64.7.96.3 entering state [received][100]
2016-05-11 03:05:04.480940 [DEBUG] sofia.c:6770 Remote SDP:
v=0
o=CiscoSystemsCCM-SIP 2000 1 IN IP4 64.7.96.6
s=SIP Call
c=IN IP4 64.7.96.3
t=0 0
m=audio 44250 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20

2016-05-11 03:05:04.480940 [DEBUG] switch_core_media.c:4161 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G7221:115:32000:20:48000:1]
2016-05-11 03:05:04.480940 [DEBUG] switch_core_media.c:4161 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G7221:107:16000:20:32000:1]
2016-05-11 03:05:04.480940 [DEBUG] switch_core_media.c:4161 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2016-05-11 03:05:04.480940 [DEBUG] switch_core_media.c:4161 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2016-05-11 03:05:04.480940 [DEBUG] switch_core_media.c:4216 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2016-05-11 03:05:04.480940 [DEBUG] switch_core_media.c:4161 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2016-05-11 03:05:04.480940 [DEBUG] switch_core_media.c:4161 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2016-05-11 03:05:04.480940 [DEBUG] switch_core_media.c:4077 Set telephone-event payload to 101@8000
2016-05-11 03:05:04.480940 [DEBUG] switch_core_media.c:2906 Set Codec sofia/external/7086872090@64.7.96.3 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2016-05-11 03:05:04.480940 [DEBUG] switch_core_codec.c:111 sofia/external/7086872090@64.7.96.3 Original read codec set to PCMU:0
2016-05-11 03:05:04.500922 [DEBUG] switch_core_media.c:4429 Set telephone-event payload to 101@8000
2016-05-11 03:05:04.500922 [DEBUG] switch_core_media.c:4485 sofia/external/7086872090@64.7.96.3 Set 2833 dtmf send payload to 101 recv payload to 101
2016-05-11 03:05:04.500922 [DEBUG] sofia.c:7146 (sofia/external/7086872090@64.7.96.3) State Change CS_NEW -> CS_INIT
2016-05-11 03:05:04.500922 [DEBUG] switch_core_state_machine.c:492 (sofia/external/7086872090@64.7.96.3) State NEW
2016-05-11 03:05:04.500922 [DEBUG] switch_core_state_machine.c:473 (sofia/external/7086872090@64.7.96.3) Running State Change CS_INIT
2016-05-11 03:05:04.500922 [DEBUG] switch_core_state_machine.c:516 (sofia/external/7086872090@64.7.96.3) State INIT
2016-05-11 03:05:04.500922 [DEBUG] mod_sofia.c:88 sofia/external/7086872090@64.7.96.3 SOFIA INIT
2016-05-11 03:05:04.500922 [DEBUG] switch_core_state_machine.c:40 sofia/external/7086872090@64.7.96.3 Standard INIT
2016-05-11 03:05:04.500922 [DEBUG] switch_core_state_machine.c:48 (sofia/external/7086872090@64.7.96.3) State Change CS_INIT -> CS_ROUTING
2016-05-11 03:05:04.500922 [DEBUG] switch_core_state_machine.c:516 (sofia/external/7086872090@64.7.96.3) State INIT going to sleep
2016-05-11 03:05:04.500922 [DEBUG] switch_core_state_machine.c:473 (sofia/external/7086872090@64.7.96.3) Running State Change CS_ROUTING
2016-05-11 03:05:04.500922 [DEBUG] switch_channel.c:2247 (sofia/external/7086872090@64.7.96.3) Callstate Change DOWN -> RINGING
2016-05-11 03:05:04.500922 [DEBUG] switch_core_state_machine.c:532 (sofia/external/7086872090@64.7.96.3) State ROUTING
2016-05-11 03:05:04.500922 [DEBUG] mod_sofia.c:141 sofia/external/7086872090@64.7.96.3 SOFIA ROUTING
2016-05-11 03:05:04.500922 [DEBUG] switch_core_state_machine.c:166 sofia/external/7086872090@64.7.96.3 Standard ROUTING
2016-05-11 03:05:04.500922 [INFO] mod_dialplan_xml.c:637 Processing Brent Sachnoff <7086872090>->6303437370 in context public
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [public->6303437370] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (PASS) [6303437370] destination_number(6303437370) =~ /6303437370/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(call_direction=inbound) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(domain_uuid=fc116b59-2402-4d62-8111-268fcc26951c) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(domain_name=besindustries.urbancom.net) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(domain=besindustries.urbancom.net) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(effective_caller_id_name=Brent Sachnoff#${caller_id_name}) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action transfer(1001 XML besindustries.urbancom.net) 
2016-05-11 03:05:04.500922 [DEBUG] switch_core_state_machine.c:216 (sofia/external/7086872090@64.7.96.3) State Change CS_ROUTING -> CS_EXECUTE
2016-05-11 03:05:04.500922 [DEBUG] switch_core_state_machine.c:532 (sofia/external/7086872090@64.7.96.3) State ROUTING going to sleep
2016-05-11 03:05:04.500922 [DEBUG] switch_core_state_machine.c:473 (sofia/external/7086872090@64.7.96.3) Running State Change CS_EXECUTE
2016-05-11 03:05:04.500922 [DEBUG] switch_core_state_machine.c:539 (sofia/external/7086872090@64.7.96.3) State EXECUTE
2016-05-11 03:05:04.500922 [DEBUG] mod_sofia.c:196 sofia/external/7086872090@64.7.96.3 SOFIA EXECUTE
2016-05-11 03:05:04.500922 [DEBUG] switch_core_state_machine.c:258 sofia/external/7086872090@64.7.96.3 Standard EXECUTE
EXECUTE sofia/external/7086872090@64.7.96.3 set(call_direction=inbound)
2016-05-11 03:05:04.500922 [DEBUG] mod_dptools.c:1498 SET sofia/external/7086872090@64.7.96.3 [call_direction]=[inbound]
EXECUTE sofia/external/7086872090@64.7.96.3 set(domain_uuid=fc116b59-2402-4d62-8111-268fcc26951c)
2016-05-11 03:05:04.500922 [DEBUG] mod_dptools.c:1498 SET sofia/external/7086872090@64.7.96.3 [domain_uuid]=[fc116b59-2402-4d62-8111-268fcc26951c]
EXECUTE sofia/external/7086872090@64.7.96.3 set(domain_name=besindustries.urbancom.net)
2016-05-11 03:05:04.500922 [DEBUG] mod_dptools.c:1498 SET sofia/external/7086872090@64.7.96.3 [domain_name]=[besindustries.urbancom.net]
EXECUTE sofia/external/7086872090@64.7.96.3 set(domain=besindustries.urbancom.net)
2016-05-11 03:05:04.500922 [DEBUG] mod_dptools.c:1498 SET sofia/external/7086872090@64.7.96.3 [domain]=[besindustries.urbancom.net]
EXECUTE sofia/external/7086872090@64.7.96.3 set(effective_caller_id_name=Brent Sachnoff#Brent Sachnoff)
2016-05-11 03:05:04.500922 [DEBUG] mod_dptools.c:1498 SET sofia/external/7086872090@64.7.96.3 [effective_caller_id_name]=[Brent Sachnoff#Brent Sachnoff]
EXECUTE sofia/external/7086872090@64.7.96.3 transfer(1001 XML besindustries.urbancom.net)
2016-05-11 03:05:04.500922 [DEBUG] switch_ivr.c:2085 (sofia/external/7086872090@64.7.96.3) State Change CS_EXECUTE -> CS_ROUTING
2016-05-11 03:05:04.500922 [NOTICE] switch_ivr.c:2092 Transfer sofia/external/7086872090@64.7.96.3 to XML[1001@besindustries.urbancom.net]
2016-05-11 03:05:04.500922 [DEBUG] switch_core_state_machine.c:539 (sofia/external/7086872090@64.7.96.3) State EXECUTE going to sleep
2016-05-11 03:05:04.500922 [DEBUG] switch_core_state_machine.c:473 (sofia/external/7086872090@64.7.96.3) Running State Change CS_ROUTING
2016-05-11 03:05:04.500922 [DEBUG] switch_core_state_machine.c:532 (sofia/external/7086872090@64.7.96.3) State ROUTING
2016-05-11 03:05:04.500922 [DEBUG] mod_sofia.c:141 sofia/external/7086872090@64.7.96.3 SOFIA ROUTING
2016-05-11 03:05:04.500922 [DEBUG] switch_core_state_machine.c:166 sofia/external/7086872090@64.7.96.3 Standard ROUTING
2016-05-11 03:05:04.500922 [INFO] mod_dialplan_xml.c:637 Processing Brent Sachnoff <7086872090>->1001 in context besindustries.urbancom.net
2016-05-11 03:05:04.520899 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7fb250041150 Connected.
2016-05-11 03:05:04.580899 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7fb250041150 released.
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->user_exists] continue=true
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (PASS) [user_exists] () =~ // break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
EXECUTE sofia/external/7086872090@64.7.96.3 set(user_exists=true)
2016-05-11 03:05:04.580899 [DEBUG] mod_dptools.c:1498 SET sofia/external/7086872090@64.7.96.3 [user_exists]=[true]
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (PASS) [user_exists] ${user_exists}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(extension_uuid=${user_data ${destination_number}@${domain_name} var extension_uuid}) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(hold_music=${user_data ${destination_number}@${domain_name} var hold_music}) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(forward_all_enabled=${user_data ${destination_number}@${domain_name} var forward_all_enabled}) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(forward_all_destination=${user_data ${destination_number}@${domain_name} var forward_all_destination}) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(forward_busy_enabled=${user_data ${destination_number}@${domain_name} var forward_busy_enabled}) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(forward_busy_destination=${user_data ${destination_number}@${domain_name} var forward_busy_destination}) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(forward_no_answer_enabled=${user_data ${destination_number}@${domain_name} var forward_no_answer_enabled}) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(forward_no_answer_destination=${user_data ${destination_number}@${domain_name} var forward_no_answer_destination}) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(forward_user_not_registered_enabled=${user_data ${destination_number}@${domain_name} var forward_user_not_registered_enabled}) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(forward_user_not_registered_destination=${user_data ${destination_number}@${domain_name} var forward_user_not_registered_destination}) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(do_not_disturb=${user_data ${destination_number}@${domain_name} var do_not_disturb}) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(call_timeout=${user_data ${destination_number}@${domain_name} var call_timeout}) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(missed_call_app=${user_data ${destination_number}@${domain_name} var missed_call_app}) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(missed_call_data=${user_data ${destination_number}@${domain_name} var missed_call_data}) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(call_screen_enabled=${user_data ${destination_number}@${domain_name} var call_screen_enabled}) INLINE
EXECUTE sofia/external/7086872090@64.7.96.3 set(call_screen_enabled=)
2016-05-11 03:05:04.600915 [DEBUG] mod_dptools.c:1498 SET sofia/external/7086872090@64.7.96.3 [call_screen_enabled]=[UNDEF]
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->call-direction] continue=true
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (PASS) [call-direction] ${call_direction}(inbound) =~ /^(inbound|outbound|local)$/ break=never
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [call-direction] ${user_exists}(true) =~ /^false$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->variables] continue=true
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (PASS) [variables] () =~ // break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 Action export(origination_callee_id_name=${destination_number}) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) 
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->user_record] continue=true
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (PASS) [user_record] () =~ // break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(user_record=${user_data ${destination_number}@${domain_name} var user_record}) INLINE
EXECUTE sofia/external/7086872090@64.7.96.3 set(user_record=)
2016-05-11 03:05:04.600915 [DEBUG] mod_dptools.c:1498 SET sofia/external/7086872090@64.7.96.3 [user_record]=[UNDEF]
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
2016-05-11 03:05:04.600915 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7fb250041150 Connected.
2016-05-11 03:05:04.600915 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7fb250041150 released.
EXECUTE sofia/external/7086872090@64.7.96.3 set(from_user_exists=false)
2016-05-11 03:05:04.600915 [DEBUG] mod_dptools.c:1498 SET sofia/external/7086872090@64.7.96.3 [from_user_exists]=[false]
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (PASS) [user_record] ${user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (PASS) [user_record] ${user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (PASS) [user_record] ${call_direction}(inbound) =~ /^inbound$/ break=never
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (PASS) [user_record] ${user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^outbound$/ break=never
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (PASS) [user_record] ${user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^local$/ break=never
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (PASS) [user_record] ${call_direction}(inbound) =~ /^inbound$/ break=never
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^outbound$/ break=never
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^local$/ break=never
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->redial] continue=true
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [redial] destination_number(1001) =~ /^(redial|\*870)$/ break=on-true
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (PASS) [redial] () =~ // break=never
Dialplan: sofia/external/7086872090@64.7.96.3 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) 
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->sip.urbancom.net.11d] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [sip.urbancom.net.11d] destination_number(1001) =~ /^\+?(\d{11})$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->agent_status] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [agent_status] destination_number(1001) =~ /^\*22$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->agent_status_id] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [agent_status_id] destination_number(1001) =~ /^\*23$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->group-intercept] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [group-intercept] destination_number(1001) =~ /^\*8$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->page-extension] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [page-extension] destination_number(1001) =~ /^\*8(\d{2,7})$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->eavesdrop] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [eavesdrop] destination_number(1001) =~ /^\*33(\d{2,7})$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->call_privacy] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [call_privacy] destination_number(1001) =~ /^\*67(\d+)$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->call_return] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [call_return] destination_number(1001) =~ /^\*69$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->extension_queue] continue=
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [extension_queue] destination_number(1001) =~ /^\*800(.*)$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->intercept-ext] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [intercept-ext] destination_number(1001) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->intercept-ext-polycom] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [intercept-ext-polycom] destination_number(1001) =~ /^\*97(\d+)$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->dx] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [dx] destination_number(1001) =~ /^dx$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->att_xfer] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [att_xfer] destination_number(1001) =~ /^att_xfer$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->extension-to-voicemail] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (PASS) [extension-to-voicemail] username(7086872090) =~ /^7086872090$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [extension-to-voicemail] destination_number(1001) =~ /^7086872090$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->send_to_voicemail] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [send_to_voicemail] destination_number(1001) =~ /^\*99(\d{2,7})$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->vmain] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [vmain] destination_number(1001) =~ /^vmain$|^\*4000$|^\*98$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->xfer_vm] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [xfer_vm] destination_number(1001) =~ /^xfer_vm$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->is_transfer] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [is_transfer] destination_number(1001) =~ /^is_transfer$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->vmain_user] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [vmain_user] destination_number(1001) =~ /^\*97$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->cf] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [cf] destination_number(1001) =~ /^cf$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->delay_echo] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [delay_echo] destination_number(1001) =~ /^\*9195$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->echo] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [echo] destination_number(1001) =~ /^\*9196$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->is_zrtp_secure] continue=true
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [is_zrtp_secure] ${zrtp_secure_media_confirmed}() =~ /^true$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 ANTI-Action eval(not_secure) 
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->milliwatt] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [milliwatt] destination_number(1001) =~ /^\*9197$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->is_secure] continue=true
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [is_secure] ${sip_via_protocol}(udp) =~ /tls/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->tone_stream] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [tone_stream] destination_number(1001) =~ /^\*9198$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->hold_music] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [hold_music] destination_number(1001) =~ /^\*9664$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->recordings] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [recordings] destination_number(1001) =~ /^\*(732)$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->directory] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [directory] destination_number(1001) =~ /^\*411$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->wake-up] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [wake-up] destination_number(1001) =~ /^\*(925)$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->valet_park] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [valet_park] destination_number(1001) =~ /^(park\+)?(\*59[0-9][0-9])$/ break=never
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [valet_park] ${sip_h_Referred-By}() =~ /sip:(.*)@.*/ break=never
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [valet_park] destination_number(1001) =~ /^(park\+)?(\*59[0-9][0-9])$/ break=never
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [valet_park] destination_number(1001) =~ /^(park\+)?(\*59[0-9][0-9])$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->operator] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [operator] destination_number(1001) =~ /^0$|^operator$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->operator-forward] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [operator-forward] destination_number(1001) =~ /^\*000$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->do-not-disturb] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [do-not-disturb] destination_number(1001) =~ /^\*78$|\*363$/ break=on-true
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [do-not-disturb] destination_number(1001) =~ /^\*79$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->call-forward] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [call-forward] destination_number(1001) =~ /^\*72$/ break=on-true
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [call-forward] destination_number(1001) =~ /^\*73$/ break=on-true
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [call-forward] destination_number(1001) =~ /^\*74$/ break=on-true
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->follow-me] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [follow-me] destination_number(1001) =~ /^\*21$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->clear_sip_auto_answer] continue=true
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [clear_sip_auto_answer] ${click_to_call}() =~ /true/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->call_screen] continue=true
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [call_screen] ${call_screen_enabled}() =~ /^true$/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 parsing [besindustries.urbancom.net->local_extension] continue=false
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (PASS) [local_extension] ${user_exists}(true) =~ /true/ break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 Action export(dialed_extension=${destination_number}) INLINE
EXECUTE sofia/external/7086872090@64.7.96.3 export(dialed_extension=1001)
2016-05-11 03:05:04.600915 [DEBUG] switch_channel.c:1293 EXPORT (export_vars) [dialed_extension]=[1001]
Dialplan: sofia/external/7086872090@64.7.96.3 Action limit(hash ${domain_name} ${destination_number} ${limit_max} ${limit_destination}) 
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (FAIL) [local_extension] ${sip_authorized}() =~ /true/ break=never
Dialplan: sofia/external/7086872090@64.7.96.3 ANTI-Action set(bind_target=both) INLINE
EXECUTE sofia/external/7086872090@64.7.96.3 set(bind_target=both)
2016-05-11 03:05:04.600915 [DEBUG] mod_dptools.c:1498 SET sofia/external/7086872090@64.7.96.3 [bind_target]=[both]
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (PASS) [local_extension] () =~ // break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 Action bind_digit_action(local,*1,exec:execute_extension,dx XML ${context},${bind_target}) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action bind_digit_action(local,*2,exec:record_session,${recordings_dir}/${domain_name}/archive/${strftime(%Y)}/${strftime(%b)}/${strftime(%d)}/${uuid}.${record_ext},${bind_target}) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action bind_digit_action(local,*3,exec:execute_extension,cf XML ${context},${bind_target}) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action bind_digit_action(local,*4,exec:execute_extension,att_xfer XML ${context},${bind_target}) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action digit_action_set_realm(local) 
Dialplan: sofia/external/7086872090@64.7.96.3 Regex (PASS) [local_extension] () =~ // break=on-false
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(hangup_after_bridge=true) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(continue_on_fail=true) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number}) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid}) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(called_party_call_group=${user_data(${dialed_extension}@${domain_name} var call_group)}) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action hash(insert/${domain_name}-last_dial/${called_party_call_group}/${uuid}) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(api_hangup_hook=lua app.lua hangup) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action bridge(user/${destination_number}@${domain_name}) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action lua(app.lua failure_handler) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action sleep(1000) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(voicemail_action=save) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(voicemail_id=${dialed_extension}) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action set(voicemail_profile=default) 
Dialplan: sofia/external/7086872090@64.7.96.3 Action lua(app.lua voicemail) 
2016-05-11 03:05:04.600915 [DEBUG] switch_core_state_machine.c:216 (sofia/external/7086872090@64.7.96.3) State Change CS_ROUTING -> CS_EXECUTE
2016-05-11 03:05:04.600915 [DEBUG] switch_core_state_machine.c:532 (sofia/external/7086872090@64.7.96.3) State ROUTING going to sleep
2016-05-11 03:05:04.600915 [DEBUG] switch_core_state_machine.c:473 (sofia/external/7086872090@64.7.96.3) Running State Change CS_EXECUTE
2016-05-11 03:05:04.600915 [DEBUG] switch_core_state_machine.c:539 (sofia/external/7086872090@64.7.96.3) State EXECUTE
2016-05-11 03:05:04.600915 [DEBUG] mod_sofia.c:196 sofia/external/7086872090@64.7.96.3 SOFIA EXECUTE
2016-05-11 03:05:04.600915 [DEBUG] switch_core_state_machine.c:258 sofia/external/7086872090@64.7.96.3 Standard EXECUTE
EXECUTE sofia/external/7086872090@64.7.96.3 set(extension_uuid=9c50b3e8-714f-4dcf-8c35-13f42500338c)
2016-05-11 03:05:04.622479 [DEBUG] mod_dptools.c:1498 SET sofia/external/7086872090@64.7.96.3 [extension_uuid]=[9c50b3e8-714f-4dcf-8c35-13f42500338c]
EXECUTE sofia/external/7086872090@64.7.96.3 set(hold_music=)
2016-05-11 03:05:04.622479 [DEBUG] mod_dptools.c:1498 SET sofia/external/7086872090@64.7.96.3 [hold_music]=[UNDEF]
EXECUTE sofia/external/7086872090@64.7.96.3 set(forward_all_enabled=)
2016-05-11 03:05:04.622479 [DEBUG] mod_dptools.c:1498 SET sofia/external/7086872090@64.7.96.3 [forward_all_enabled]=[UNDEF]
EXECUTE sofia/external/7086872090@64.7.96.3 set(forward_all_destination=)
2016-05-11 03:05:04.622479 [DEBUG] mod_dptools.c:1498 SET sofia/external/7086872090@64.7.96.3 [forward_all_destination]=[UNDEF]
EXECUTE sofia/external/7086872090@64.7.96.3 set(forward_busy_enabled=)
2016-05-11 03:05:04.622479 [DEBUG] mod_dptools.c:1498 SET sofia/external/7086872090@64.7.96.3 [forward_busy_enabled]=[UNDEF]
EXECUTE sofia/external/7086872090@64.7.96.3 set(forward_busy_destination=)
2016-05-11 03:05:04.622479 [DEBUG] mod_dptools.c:1498 SET sofia/external/7086872090@64.7.96.3 [forward_busy_destination]=[UNDEF]
EXECUTE sofia/external/7086872090@64.7.96.3 set(forward_no_answer_enabled=)
2016-05-11 03:05:04.660920 [DEBUG] mod_dptools.c:1498 SET sofia/external/7086872090@64.7.96.3 [forward_no_answer_enabled]=[UNDEF]
EXECUTE sofia/external/7086872090@64.7.96.3 set(forward_no_answer_destination=)
2016-05-11 03:05:04.660920 [DEBUG] mod_dptools.c:1498 SET sofia/external/7086872090@64.7.96.3 [forward_no_answer_destination]=[UNDEF]
EXECUTE sofia/external/7086872090@64.7.96.3 set(forward_user_not_registered_enabled=)
2016-05-11 03:05:04.660920 [DEBUG] mod_dptools.c:1498 SET sofia/external/7086872090@64.7.96.3 [forward_user_not_registered_enabled]=[UNDEF]
EXECUTE sofia/external/7086872090@64.7.96.3 set(forward_user_not_registered_destination=)
2016-05-11 03:05:04.680920 [DEBUG] mod_dptools.c:1498 SET sofia/external/7086872090@64.7.96.3 [forward_user_not_registered_destination]=[UNDEF]
EXECUTE sofia/external/7086872090@64.7.96.3 set(do_not_disturb=)
2016-05-11 03:05:04.680920 [DEBUG] mod_dptools.c:1498 SET sofia/external/7086872090@64.7.96.3 [do_not_disturb]=[UNDEF]
EXECUTE sofia/external/7086872090@64.7.96.3 set(call_timeout=30)
2016-05-11 03:05:04.680920 [DEBUG] mod_dptools.c:1498 SET sofia/external/7086872090@64.7.96.3 [call_timeout]=[30]
EXECUTE sofia/external/7086872090@64.7.96.3 set(missed_call_app=)
2016-05-11 03:05:04.680920 [DEBUG] mod_dptools.c:1498 SET sofia/external/7086872090@64.7.96.3 [missed_call_app]=[UNDEF]
EXECUTE sofia/external/7086872090@64.7.96.3 set(missed_call_data=)
2016-05-11 03:05:04.700921 [DEBUG] mod_dptools.c:1498 SET sofia/external/7086872090@64.7.96.3 [missed_call_data]=[UNDEF]
EXECUTE sofia/external/7086872090@64.7.96.3 export(origination_callee_id_name=1001)
2016-05-11 03:05:04.700921 [DEBUG] switch_channel.c:1293 EXPORT (export_vars) [origination_callee_id_name]=[1001]
EXECUTE sofia/external/7086872090@64.7.96.3 set(RFC2822_DATE=Wed, 11 May 2016 03:05:04 -0500)
2016-05-11 03:05:04.700921 [DEBUG] mod_dptools.c:1498 SET sofia/external/7086872090@64.7.96.3 [RFC2822_DATE]=[Wed, 11 May 2016 03:05:04 -0500]
EXECUTE sofia/external/7086872090@64.7.96.3 hash(insert/besindustries.urbancom.net-last_dial/7086872090/1001)
EXECUTE sofia/external/7086872090@64.7.96.3 eval(not_secure)
EXECUTE sofia/external/7086872090@64.7.96.3 limit(hash besindustries.urbancom.net 1001  )
2016-05-11 03:05:04.700921 [DEBUG] switch_limit.c:126 incr called: besindustries.urbancom.net_1001 max:-1, interval:0
2016-05-11 03:05:04.700921 [DEBUG] mod_hash.c:194 Usage for besindustries.urbancom.net_1001 is now 1
EXECUTE sofia/external/7086872090@64.7.96.3 bind_digit_action(local,*1,exec:execute_extension,dx XML besindustries.urbancom.net,both)
2016-05-11 03:05:04.700921 [INFO] switch_ivr_async.c:214 Digit parser DPTOOLS: Setting realm to 'local'
2016-05-11 03:05:04.700921 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *1/local/0 callback: 0x7fb2d5279400 data: 0x7fb250031b48
2016-05-11 03:05:04.700921 [INFO] switch_ivr_async.c:214 Digit parser DPTOOLS: Setting realm to 'local'
2016-05-11 03:05:04.700921 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *1/local/0 callback: 0x7fb2d5279400 data: 0x7fb250031bc8
EXECUTE sofia/external/7086872090@64.7.96.3 bind_digit_action(local,*2,exec:record_session,/var/lib/freeswitch/recordings/besindustries.urbancom.net/archive/2016/May/11/11828066-174f-11e6-b94d-8dcc9e1d3d65.wav,both)
2016-05-11 03:05:04.700921 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *2/local/0 callback: 0x7fb2d5279400 data: 0x7fb250031e38
2016-05-11 03:05:04.700921 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *2/local/0 callback: 0x7fb2d5279400 data: 0x7fb250031f08
EXECUTE sofia/external/7086872090@64.7.96.3 bind_digit_action(local,*3,exec:execute_extension,cf XML besindustries.urbancom.net,both)
2016-05-11 03:05:04.700921 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *3/local/0 callback: 0x7fb2d5279400 data: 0x7fb2500320c8
2016-05-11 03:05:04.700921 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *3/local/0 callback: 0x7fb2d5279400 data: 0x7fb250032148
EXECUTE sofia/external/7086872090@64.7.96.3 bind_digit_action(local,*4,exec:execute_extension,att_xfer XML besindustries.urbancom.net,both)
2016-05-11 03:05:04.700921 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *4/local/0 callback: 0x7fb2d5279400 data: 0x7fb2500322c8
2016-05-11 03:05:04.700921 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *4/local/0 callback: 0x7fb2d5279400 data: 0x7fb250032348
EXECUTE sofia/external/7086872090@64.7.96.3 digit_action_set_realm(local)
2016-05-11 03:05:04.700921 [INFO] switch_ivr_async.c:214 Digit parser DPTOOLS: Setting realm to 'local'
EXECUTE sofia/external/7086872090@64.7.96.3 set(hangup_after_bridge=true)
2016-05-11 03:05:04.700921 [DEBUG] mod_dptools.c:1498 SET sofia/external/7086872090@64.7.96.3 [hangup_after_bridge]=[true]
EXECUTE sofia/external/7086872090@64.7.96.3 set(continue_on_fail=true)
2016-05-11 03:05:04.700921 [DEBUG] mod_dptools.c:1498 SET sofia/external/7086872090@64.7.96.3 [continue_on_fail]=[true]
EXECUTE sofia/external/7086872090@64.7.96.3 hash(insert/besindustries.urbancom.net-call_return/1001/7086872090)
EXECUTE sofia/external/7086872090@64.7.96.3 hash(insert/besindustries.urbancom.net-last_dial_ext/1001/11828066-174f-11e6-b94d-8dcc9e1d3d65)
EXECUTE sofia/external/7086872090@64.7.96.3 set(called_party_call_group=)
2016-05-11 03:05:04.700921 [DEBUG] mod_dptools.c:1498 SET sofia/external/7086872090@64.7.96.3 [called_party_call_group]=[UNDEF]
EXECUTE sofia/external/7086872090@64.7.96.3 hash(insert/besindustries.urbancom.net-last_dial//11828066-174f-11e6-b94d-8dcc9e1d3d65)
EXECUTE sofia/external/7086872090@64.7.96.3 set(api_hangup_hook=lua app.lua hangup)
2016-05-11 03:05:04.700921 [DEBUG] mod_dptools.c:1498 SET sofia/external/7086872090@64.7.96.3 [api_hangup_hook]=[lua app.lua hangup]
EXECUTE sofia/external/7086872090@64.7.96.3 bridge(user/1001@besindustries.urbancom.net)
2016-05-11 03:05:04.700921 [DEBUG] switch_channel.c:1247 sofia/external/7086872090@64.7.96.3 EXPORTING[export_vars] [dialed_extension]=[1001] to event
2016-05-11 03:05:04.700921 [DEBUG] switch_channel.c:1247 sofia/external/7086872090@64.7.96.3 EXPORTING[export_vars] [origination_callee_id_name]=[1001] to event
2016-05-11 03:05:04.700921 [DEBUG] switch_ivr_originate.c:2128 Parsing global variables
2016-05-11 03:05:04.720903 [DEBUG] switch_channel.c:1247 sofia/external/7086872090@64.7.96.3 EXPORTING[export_vars] [dialed_extension]=[1001] to event
2016-05-11 03:05:04.720903 [DEBUG] switch_channel.c:1247 sofia/external/7086872090@64.7.96.3 EXPORTING[export_vars] [origination_callee_id_name]=[1001] to event
2016-05-11 03:05:04.720903 [DEBUG] switch_ivr_originate.c:2128 Parsing global variables
2016-05-11 03:05:04.720903 [NOTICE] switch_channel.c:1101 New Channel sofia/internal/1001@73.72.98.76:5060 [11a47b6c-174f-11e6-b982-8dcc9e1d3d65]
2016-05-11 03:05:04.720903 [DEBUG] mod_sofia.c:4776 (sofia/internal/1001@73.72.98.76:5060) State Change CS_NEW -> CS_INIT
2016-05-11 03:05:04.720903 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1001@73.72.98.76:5060) Running State Change CS_INIT
2016-05-11 03:05:04.720903 [DEBUG] switch_core_state_machine.c:516 (sofia/internal/1001@73.72.98.76:5060) State INIT
2016-05-11 03:05:04.720903 [DEBUG] mod_sofia.c:88 sofia/internal/1001@73.72.98.76:5060 SOFIA INIT
2016-05-11 03:05:04.720903 [DEBUG] sofia_glue.c:1257 sofia/internal/1001@73.72.98.76:5060 sending invite version: 1.6.6  64bit
Local SDP:
v=0
o=FreeSWITCH 1462924644 1462924645 IN IP4 64.7.99.27
s=FreeSWITCH
c=IN IP4 64.7.99.27
t=0 0
m=audio 29260 RTP/AVP 0 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
a=sendrecv

2016-05-11 03:05:04.720903 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1001@73.72.98.76:5060 Standard INIT
2016-05-11 03:05:04.720903 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1001@73.72.98.76:5060) State Change CS_INIT -> CS_ROUTING
2016-05-11 03:05:04.720903 [DEBUG] switch_core_state_machine.c:516 (sofia/internal/1001@73.72.98.76:5060) State INIT going to sleep
2016-05-11 03:05:04.720903 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1001@73.72.98.76:5060) Running State Change CS_ROUTING
2016-05-11 03:05:04.720903 [DEBUG] switch_core_state_machine.c:532 (sofia/internal/1001@73.72.98.76:5060) State ROUTING
2016-05-11 03:05:04.720903 [DEBUG] mod_sofia.c:141 sofia/internal/1001@73.72.98.76:5060 SOFIA ROUTING
2016-05-11 03:05:04.720903 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1001@73.72.98.76:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2016-05-11 03:05:04.720903 [DEBUG] switch_core_state_machine.c:532 (sofia/internal/1001@73.72.98.76:5060) State ROUTING going to sleep
send 1231 bytes to udp/[73.72.98.76]:5060 at 03:05:04.724623:
   ------------------------------------------------------------------------
   INVITE sip:1001@73.72.98.76:5060 SIP/2.0
   Via: SIP/2.0/UDP 64.7.99.27;rport;branch=z9hG4bKaUmBNmUZB1F0Q
   Max-Forwards: 67
   From: "Brent Sachnoff#Brent Sachnoff" <sip:7086872090@besindustries.urbancom.net>;tag=4g332eaZj4FyN
   To: <sip:1001@73.72.98.76:5060>
   Call-ID: e9030588-91f1-1234-b3a4-005056b9942b
   CSeq: 91140888 INVITE
   Contact: <sip:mod_sofia@64.7.99.27:5060>
   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: 240
   P-hint: mediaproxy applied
   X-FS-Support: update_display,send_info
2016-05-11 03:05:04.720903 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1001@73.72.98.76:5060) Running State Change CS_CONSUME_MEDIA
   Remote-Party-ID: "Brent Sachnoff#Brent Sachnoff" <sip:7086872090@besindustries.urbancom.net>;party=calling;screen=yes;privacy=off
   
   v=0
   o=FreeSWITCH 1462924644 1462924645 IN IP4 64.7.99.27
   s=FreeSWITCH
   c=IN IP4 64.7.99.27
   t=0 0
   m=audio 29260 RTP/AVP 0 101 13
   a=rtpmap:0 PCMU/8000
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-16
   a=rtpmap:13 CN/8000
   a=ptime:20
   ------------------------------------------------------------------------
2016-05-11 03:05:04.720903 [DEBUG] switch_core_state_machine.c:551 (sofia/internal/1001@73.72.98.76:5060) State CONSUME_MEDIA
2016-05-11 03:05:04.720903 [DEBUG] switch_core_state_machine.c:551 (sofia/internal/1001@73.72.98.76:5060) State CONSUME_MEDIA going to sleep
2016-05-11 03:05:04.720903 [DEBUG] sofia.c:6760 Channel sofia/internal/1001@73.72.98.76:5060 entering state [calling][0]
recv 394 bytes from udp/[73.72.98.76]:5060 at 03:05:04.748741:
   ------------------------------------------------------------------------
   SIP/2.0 100 Trying
   Call-ID: e9030588-91f1-1234-b3a4-005056b9942b
   CSeq: 91140888 INVITE
   Content-Length: 0
   From: "Brent Sachnoff#Brent Sachnoff" <sip:7086872090@besindustries.urbancom.net>;tag=4g332eaZj4FyN
   To: <sip:1001@73.72.98.76:5060>;tag=SP1935f3a4edaa5781a
   Via: SIP/2.0/UDP 10.20.12.27;branch=z9hG4bKaUmBNmUZB1F0Q;received=10.20.12.27;rport=5060
   Server: OBIHAI/OBi1062-5.0.0.3223
   
   ------------------------------------------------------------------------
recv 575 bytes from udp/[73.72.98.76]:5060 at 03:05:05.027017:
   ------------------------------------------------------------------------
   SIP/2.0 180 Ringing
   Call-ID: e9030588-91f1-1234-b3a4-005056b9942b
   CSeq: 91140888 INVITE
   Content-Length: 0
   From: "Brent Sachnoff#Brent Sachnoff" <sip:7086872090@besindustries.urbancom.net>;tag=4g332eaZj4FyN
   To: <sip:1001@73.72.98.76:5060>;tag=SP1935f3a4edaa5781a
   Via: SIP/2.0/UDP 10.20.12.27;branch=z9hG4bKaUmBNmUZB1F0Q;received=10.20.12.27;rport=5060
   Server: OBIHAI/OBi1062-5.0.0.3223
   Contact: <sip:1001@73.72.98.76:5060>
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Allow-Events: hold,talk,dialog
   
   ------------------------------------------------------------------------
2016-05-11 03:05:05.020998 [DEBUG] sofia.c:6760 Channel sofia/internal/1001@73.72.98.76:5060 entering state [proceeding][180]
2016-05-11 03:05:05.020998 [NOTICE] sofia.c:6862 Ring-Ready sofia/internal/1001@73.72.98.76:5060!
2016-05-11 03:05:05.020998 [DEBUG] switch_channel.c:3340 (sofia/internal/1001@73.72.98.76:5060) Callstate Change DOWN -> RINGING
2016-05-11 03:05:05.040976 [INFO] switch_ivr_originate.c:1216 Sending early media
2016-05-11 03:05:05.040976 [DEBUG] switch_core_media.c:6033 AUDIO RTP [sofia/external/7086872090@64.7.96.3] 10.20.12.27 port 27174 -> 64.7.96.3 port 44250 codec: 0 ms: 20
2016-05-11 03:05:05.040976 [DEBUG] switch_rtp.c:3802 Starting timer [soft] 160 bytes per 20ms
2016-05-11 03:05:05.040976 [DEBUG] switch_core_media.c:6332 sofia/external/7086872090@64.7.96.3 Set 2833 dtmf send payload to 101
2016-05-11 03:05:05.040976 [DEBUG] switch_core_media.c:6339 sofia/external/7086872090@64.7.96.3 Set 2833 dtmf receive payload to 101
2016-05-11 03:05:05.040976 [DEBUG] switch_core_media.c:6362 sofia/external/7086872090@64.7.96.3 Set rtp dtmf delay to 40
2016-05-11 03:05:05.040976 [DEBUG] mod_sofia.c:2330 Ring SDP:
v=0
o=FreeSWITCH 1462926731 1462926732 IN IP4 64.7.99.27
s=FreeSWITCH
c=IN IP4 64.7.99.27
t=0 0
m=audio 27174 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

2016-05-11 03:05:05.040976 [NOTICE] mod_sofia.c:2333 Pre-Answer sofia/external/7086872090@64.7.96.3!
2016-05-11 03:05:05.040976 [DEBUG] switch_channel.c:3468 (sofia/external/7086872090@64.7.96.3) Callstate Change RINGING -> EARLY
2016-05-11 03:05:05.040976 [DEBUG] switch_ivr_originate.c:1274 Raw Codec Activation Success L16@8000hz 1 channel 20ms
2016-05-11 03:05:05.040976 [DEBUG] switch_core_codec.c:221 sofia/external/7086872090@64.7.96.3 Push codec L16:100
2016-05-11 03:05:05.040976 [DEBUG] switch_ivr_originate.c:1343 Play Ringback Tone [%(2000,4000,440,480)]
send 1171 bytes to udp/[64.7.96.3]:5060 at 03:05:05.050024:
   ------------------------------------------------------------------------
   SIP/2.0 183 Session Progress
   Via: SIP/2.0/UDP 64.7.96.3;branch=z9hG4bKfe59.feb100c6.0
   Via: SIP/2.0/UDP 64.7.96.6:5060;branch=z9hG4bK194a11786434f
   Record-Route: <sip:64.7.96.3;lr=on;ftag=eea75a70-f420-4416-8968-d6e5dfadb3f4-30174388;mp=yes;vsf=AAAAAAEACAB4AQYeDh55ABoYNy45Ni4z>
   From: "Brent Sachnoff" <sip:7086872090@64.7.96.3>;tag=eea75a70-f420-4416-8968-d6e5dfadb3f4-30174388
   To: <sip:16303437370@64.7.96.3>;tag=pj7BjD4ZFQ1DQ
   Call-ID: ffe3d80-7321e7b0-bfc3-6600740@64.7.96.6
   CSeq: 101 INVITE
   Contact: <sip:16303437370@64.7.99.27:5080;transport=udp>
   User-Agent: FreeSWITCH
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
   Supported: timer, path, replaces
   Allow-Events: talk, hold, conference, refer
   Content-Type: application/sdp
   Content-Disposition: session
   Content-Length: 216
   Remote-Party-ID: "6303437370" <sip:6303437370@64.7.96.3>;party=calling;privacy=off;screen=no
   
   v=0
   o=FreeSWITCH 1462926731 1462926732 IN IP4 64.7.99.27
   s=FreeSWITCH
   c=IN IP4 64.7.99.27
   t=0 0
   m=audio 27174 RTP/AVP 0 101
   a=rtpmap:0 PCMU/8000
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-16
   a=ptime:20
   ------------------------------------------------------------------------
2016-05-11 03:05:05.060917 [DEBUG] sofia.c:6760 Channel sofia/external/7086872090@64.7.96.3 entering state [early][183]
2016-05-11 03:05:05.100897 [DEBUG] switch_rtp.c:6654 Correct audio ip/port confirmed.
recv 955 bytes from udp/[73.72.98.76]:5060 at 03:05:06.945970:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Call-ID: e9030588-91f1-1234-b3a4-005056b9942b
   CSeq: 91140888 INVITE
   Content-Length: 229
   From: "Brent Sachnoff#Brent Sachnoff" <sip:7086872090@besindustries.urbancom.net>;tag=4g332eaZj4FyN
   To: <sip:1001@73.72.98.76:5060>;tag=SP1935f3a4edaa5781a
   Via: SIP/2.0/UDP 10.20.12.27;branch=z9hG4bKaUmBNmUZB1F0Q;received=10.20.12.27;rport=5060
   Server: OBIHAI/OBi1062-5.0.0.3223
   Contact: <sip:1001@73.72.98.76:5060>
   Supported: replaces, eventlist, record-aware
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Accept: application/vnd.etsi.aoc+xml,application/dtmf-relay,application/sdp
   Allow-Events: hold,talk,dialog
   Content-Type: application/sdp
   
   v=0
   o=- 12418691 1 IN IP4 73.72.98.76
   s=-
   c=IN IP4 73.72.98.76
   t=0 0
   m=audio 16606 RTP/AVP 0 101
   a=rtpmap:0 PCMU/8000
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-15
   a=sendrecv
   a=ptime:20
   a=xg726bitorder:big-endian
   ------------------------------------------------------------------------
2016-05-11 03:05:06.940917 [DEBUG] sofia.c:6760 Channel sofia/internal/1001@73.72.98.76:5060 entering state [completing][200]
2016-05-11 03:05:06.940917 [DEBUG] sofia.c:6770 Remote SDP:
v=0
o=- 12418691 1 IN IP4 73.72.98.76
s=-
c=IN IP4 73.72.98.76
t=0 0
m=audio 16606 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=xg726bitorder:big-endian

send 408 bytes to udp/[73.72.98.76]:5060 at 03:05:06.948349:
   ------------------------------------------------------------------------
   ACK sip:1001@73.72.98.76:5060 SIP/2.0
   Via: SIP/2.0/UDP 64.7.99.27;rport;branch=z9hG4bKB4D4pFc3895jK
   Max-Forwards: 70
   From: "Brent Sachnoff#Brent Sachnoff" <sip:7086872090@besindustries.urbancom.net>;tag=4g332eaZj4FyN
   To: <sip:1001@73.72.98.76:5060>;tag=SP1935f3a4edaa5781a
   Call-ID: e9030588-91f1-1234-b3a4-005056b9942b
   CSeq: 91140888 ACK
   Contact: <sip:mod_sofia@64.7.99.27:5060>
   Content-Length: 0
   
   ------------------------------------------------------------------------
2016-05-11 03:05:06.940917 [DEBUG] sofia.c:6760 Channel sofia/internal/1001@73.72.98.76:5060 entering state [ready][200]
2016-05-11 03:05:06.940917 [DEBUG] switch_core_media.c:4161 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2016-05-11 03:05:06.940917 [DEBUG] switch_core_media.c:4216 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2016-05-11 03:05:06.940917 [DEBUG] switch_core_media.c:4077 Set telephone-event payload to 101@8000
2016-05-11 03:05:06.940917 [DEBUG] switch_core_media.c:2906 Set Codec sofia/internal/1001@73.72.98.76:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2016-05-11 03:05:06.940917 [DEBUG] switch_core_codec.c:111 sofia/internal/1001@73.72.98.76:5060 Original read codec set to PCMU:0
2016-05-11 03:05:06.940917 [DEBUG] switch_core_media.c:4429 Set telephone-event payload to 101@8000
2016-05-11 03:05:06.940917 [DEBUG] switch_core_media.c:4485 sofia/internal/1001@73.72.98.76:5060 Set 2833 dtmf send payload to 101 recv payload to 101
2016-05-11 03:05:06.940917 [DEBUG] switch_core_media.c:6033 AUDIO RTP [sofia/internal/1001@73.72.98.76:5060] 10.20.12.27 port 29260 -> 73.72.98.76 port 16606 codec: 0 ms: 20
2016-05-11 03:05:06.940917 [DEBUG] switch_rtp.c:3802 Starting timer [soft] 160 bytes per 20ms
2016-05-11 03:05:06.940917 [DEBUG] switch_core_media.c:6332 sofia/internal/1001@73.72.98.76:5060 Set 2833 dtmf send payload to 101
2016-05-11 03:05:06.940917 [DEBUG] switch_core_media.c:6339 sofia/internal/1001@73.72.98.76:5060 Set 2833 dtmf receive payload to 101
2016-05-11 03:05:06.940917 [DEBUG] switch_core_media.c:6362 sofia/internal/1001@73.72.98.76:5060 Set rtp dtmf delay to 40
2016-05-11 03:05:06.940917 [NOTICE] sofia.c:7724 Channel [sofia/internal/1001@73.72.98.76:5060] has been answered
2016-05-11 03:05:06.940917 [DEBUG] switch_channel.c:3767 (sofia/internal/1001@73.72.98.76:5060) Callstate Change RINGING -> ACTIVE
2016-05-11 03:05:06.960923 [DEBUG] switch_core_codec.c:246 sofia/external/7086872090@64.7.96.3 Restore previous codec PCMU:0.
2016-05-11 03:05:06.960923 [DEBUG] mod_sofia.c:799 Local SDP sofia/external/7086872090@64.7.96.3:
v=0
o=FreeSWITCH 1462926731 1462926733 IN IP4 64.7.99.27
s=FreeSWITCH
c=IN IP4 64.7.99.27
t=0 0
m=audio 27174 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 1173 bytes to udp/[64.7.96.3]:5060 at 03:05:06.967610:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 64.7.96.3;branch=z9hG4bKfe59.feb100c6.0
   Via: SIP/2.0/UDP 64.7.96.6:5060;branch=z9hG4bK194a11786434f
2016-05-11 03:05:06.960923 [NOTICE] switch_ivr_originate.c:3550 Channel [sofia/external/7086872090@64.7.96.3] has been answered
   Record-Route: <sip:64.7.96.3;lr=on;ftag=eea75a70-f420-4416-8968-d6e5dfadb3f4-30174388;mp=yes;vsf=AAAAAAEACAB4AQYeDh55ABoYNy45Ni4z>
   From: "Brent Sachnoff" <sip:7086872090@64.7.96.3>;tag=eea75a70-f420-4416-8968-d6e5dfadb3f4-30174388
   To: <sip:16303437370@64.7.96.3>;tag=pj7BjD4ZFQ1DQ
   Call-ID: ffe3d80-7321e7b0-bfc3-6600740@64.7.96.6
   CSeq: 101 INVITE
   Contact: <sip:16303437370@64.7.99.27:5080;transport=udp>
   User-Agent: FreeSWITCH
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
   Require: timer
   Supported: timer, path, replaces
   Allow-Events: talk, hold, conference, refer
   Session-Expires: 1800;refresher=uac
   Content-Type: application/sdp
   Content-Disposition: session
   Content-Length: 216
   Remote-Party-ID: "1001" <sip:1001@64.7.96.3>;party=calling;privacy=off;screen=no
   
   v=0
   o=FreeSWITCH 1462926731 1462926732 IN IP4 64.7.99.27
   s=FreeSWITCH
   c=IN IP4 64.7.99.27
   t=0 0
   m=audio 27174 RTP/AVP 0 101
   a=rtpmap:0 PCMU/8000
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-16
   a=ptime:20
   ------------------------------------------------------------------------
2016-05-11 03:05:06.960923 [DEBUG] switch_channel.c:3767 (sofia/external/7086872090@64.7.96.3) Callstate Change EARLY -> ACTIVE
2016-05-11 03:05:06.960923 [DEBUG] sofia.c:6760 Channel sofia/external/7086872090@64.7.96.3 entering state [completed][200]
2016-05-11 03:05:06.960923 [DEBUG] switch_ivr_originate.c:3608 Originate Resulted in Success: [sofia/internal/1001@73.72.98.76:5060]
2016-05-11 03:05:06.960923 [DEBUG] switch_ivr_originate.c:3608 Originate Resulted in Success: [sofia/internal/1001@73.72.98.76:5060]
2016-05-11 03:05:06.960923 [DEBUG] switch_ivr_bridge.c:1591 (sofia/internal/1001@73.72.98.76:5060) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
2016-05-11 03:05:06.960923 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1001@73.72.98.76:5060) Running State Change CS_EXCHANGE_MEDIA
2016-05-11 03:05:06.960923 [DEBUG] switch_core_state_machine.c:542 (sofia/internal/1001@73.72.98.76:5060) State EXCHANGE_MEDIA
2016-05-11 03:05:06.960923 [DEBUG] mod_sofia.c:613 SOFIA EXCHANGE_MEDIA
recv 610 bytes from udp/[64.7.96.3]:5060 at 03:05:06.985481:
   ------------------------------------------------------------------------
   ACK sip:16303437370@64.7.99.27:5080;transport=udp SIP/2.0
   Record-Route: <sip:64.7.96.3;lr=on;ftag=eea75a70-f420-4416-8968-d6e5dfadb3f4-30174388>
   Via: SIP/2.0/UDP 64.7.96.3;branch=z9hG4bKfe59.feb100c6.2
   Via: SIP/2.0/UDP 64.7.96.6:5060;branch=z9hG4bK194a25d5cacb9
   From: "Brent Sachnoff" <sip:7086872090@64.7.96.3>;tag=eea75a70-f420-4416-8968-d6e5dfadb3f4-30174388
   To: <sip:16303437370@64.7.96.3>;tag=pj7BjD4ZFQ1DQ
   Date: Wed, 11 May 2016 08:05:04 GMT
   Call-ID: ffe3d80-7321e7b0-bfc3-6600740@64.7.96.6
   Max-Forwards: 69
   CSeq: 101 ACK
   Allow-Events: presence, kpml
   Content-Length: 0
   P-hint: rr-enforced
   
   ------------------------------------------------------------------------
2016-05-11 03:05:06.980903 [DEBUG] sofia.c:6760 Channel sofia/external/7086872090@64.7.96.3 entering state [ready][200]
2016-05-11 03:05:07.020906 [DEBUG] switch_rtp.c:6654 Correct audio ip/port confirmed.
2016-05-11 03:05:07.440904 [DEBUG] switch_rtp.c:6654 Correct audio ip/port confirmed.
recv 479 bytes from udp/[73.72.98.76]:5060 at 03:05:08.180976:
   ------------------------------------------------------------------------
   BYE sip:mod_sofia@10.20.12.27:5060 SIP/2.0
   Call-ID: e9030588-91f1-1234-b3a4-005056b9942b
   Content-Length: 0
   CSeq: 8001 BYE
   From: <sip:1001@172.20.21.151>;tag=SP1935f3a4edaa5781a
   Max-Forwards: 70
   To: "Brent Sachnoff#Brent Sachnoff" <sip:7086872090@besindustries.urbancom.net>;tag=4g332eaZj4FyN
   Via: SIP/2.0/UDP 73.72.98.76:5060;branch=z9hG4bK-f3fda812;rport
   User-Agent: OBIHAI/OBi1062-5.0.0.3223
   X-RTP-Stat: PS=35,OS=6020,PR=56,OR=9632,PL=0,JI=0,DU=0,EN=G711U,DE=G711U
   
   ------------------------------------------------------------------------
2016-05-11 03:05:08.180958 [NOTICE] sofia.c:952 Hangup sofia/internal/1001@73.72.98.76:5060 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
2016-05-11 03:05:08.180958 [DEBUG] switch_ivr_bridge.c:699 sofia/internal/1001@73.72.98.76:5060 ending bridge by request from write function
send 493 bytes to udp/[73.72.98.76]:5060 at 03:05:08.187954:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 73.72.98.76:5060;branch=z9hG4bK-f3fda812;rport=5060
   From: <sip:1001@172.20.21.151>;tag=SP1935f3a4edaa5781a
   To: "Brent Sachnoff#Brent Sachnoff" <sip:7086872090@besindustries.urbancom.net>;tag=4g332eaZj4FyN
   Call-ID: e9030588-91f1-1234-b3a4-005056b9942b
   CSeq: 8001 BYE
   User-Agent: FreeSWITCH
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, path, replaces
   Content-Length: 0
   
   ------------------------------------------------------------------------
2016-05-11 03:05:08.180958 [DEBUG] switch_ivr_bridge.c:778 BRIDGE THREAD DONE [sofia/external/7086872090@64.7.96.3]
2016-05-11 03:05:08.180958 [DEBUG] switch_ivr_bridge.c:1689 sofia/internal/1001@73.72.98.76:5060 skip receive message [UNBRIDGE] (channel is hungup already)
2016-05-11 03:05:08.180958 [NOTICE] switch_ivr_bridge.c:1741 Hangup sofia/external/7086872090@64.7.96.3 [CS_EXECUTE] [NORMAL_CLEARING]
2016-05-11 03:05:08.180958 [DEBUG] mod_hash.c:297 Usage for besindustries.urbancom.net_1001 is now 0
2016-05-11 03:05:08.180958 [DEBUG] switch_core_session.c:2796 sofia/external/7086872090@64.7.96.3 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2016-05-11 03:05:08.180958 [DEBUG] switch_core_state_machine.c:539 (sofia/external/7086872090@64.7.96.3) State EXECUTE going to sleep
2016-05-11 03:05:08.180958 [DEBUG] switch_core_state_machine.c:473 (sofia/external/7086872090@64.7.96.3) Running State Change CS_HANGUP
2016-05-11 03:05:08.180958 [DEBUG] switch_core_state_machine.c:739 (sofia/external/7086872090@64.7.96.3) Callstate Change ACTIVE -> HANGUP
2016-05-11 03:05:08.180958 [DEBUG] switch_core_state_machine.c:741 (sofia/external/7086872090@64.7.96.3) State HANGUP
2016-05-11 03:05:08.180958 [DEBUG] mod_sofia.c:425 sofia/external/7086872090@64.7.96.3 Overriding SIP cause 480 with 200 from the other leg
2016-05-11 03:05:08.180958 [DEBUG] mod_sofia.c:431 Channel sofia/external/7086872090@64.7.96.3 hanging up, cause: NORMAL_CLEARING
2016-05-11 03:05:08.180958 [DEBUG] mod_sofia.c:484 Sending BYE to sofia/external/7086872090@64.7.96.3
2016-05-11 03:05:08.180958 [DEBUG] switch_core_state_machine.c:60 sofia/external/7086872090@64.7.96.3 Standard HANGUP, cause: NORMAL_CLEARING
2016-05-11 03:05:08.180958 [DEBUG] switch_core_state_machine.c:741 (sofia/external/7086872090@64.7.96.3) State HANGUP going to sleep
2016-05-11 03:05:08.180958 [DEBUG] switch_ivr_bridge.c:705 sofia/internal/1001@73.72.98.76:5060 ending bridge by request from read function
2016-05-11 03:05:08.180958 [DEBUG] switch_ivr_bridge.c:778 BRIDGE THREAD DONE [sofia/internal/1001@73.72.98.76:5060]
2016-05-11 03:05:08.180958 [DEBUG] switch_core_state_machine.c:542 (sofia/internal/1001@73.72.98.76:5060) State EXCHANGE_MEDIA going to sleep
2016-05-11 03:05:08.180958 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1001@73.72.98.76:5060) Running State Change CS_HANGUP
2016-05-11 03:05:08.180958 [DEBUG] switch_core_state_machine.c:739 (sofia/internal/1001@73.72.98.76:5060) Callstate Change ACTIVE -> HANGUP
2016-05-11 03:05:08.180958 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1001@73.72.98.76:5060) State HANGUP
2016-05-11 03:05:08.180958 [DEBUG] mod_sofia.c:431 Channel sofia/internal/1001@73.72.98.76:5060 hanging up, cause: NORMAL_CLEARING
2016-05-11 03:05:08.180958 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1001@73.72.98.76:5060 Standard HANGUP, cause: NORMAL_CLEARING
2016-05-11 03:05:08.180958 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1001@73.72.98.76:5060) State HANGUP going to sleep
2016-05-11 03:05:08.180958 [DEBUG] switch_core_state_machine.c:508 (sofia/internal/1001@73.72.98.76:5060) State Change CS_HANGUP -> CS_REPORTING
2016-05-11 03:05:08.180958 [DEBUG] switch_core_state_machine.c:473 (sofia/internal/1001@73.72.98.76:5060) Running State Change CS_REPORTING
2016-05-11 03:05:08.180958 [DEBUG] switch_core_state_machine.c:827 (sofia/internal/1001@73.72.98.76:5060) State REPORTING
2016-05-11 03:05:08.180958 [DEBUG] switch_core_state_machine.c:104 sofia/internal/1001@73.72.98.76:5060 Standard REPORTING, cause: NORMAL_CLEARING
2016-05-11 03:05:08.180958 [DEBUG] switch_core_state_machine.c:827 (sofia/internal/1001@73.72.98.76:5060) State REPORTING going to sleep
send 760 bytes to udp/[64.7.96.3]:5060 at 03:05:08.190856:
   ------------------------------------------------------------------------
   BYE sip:6006@64.7.96.6:5060 SIP/2.0
   Via: SIP/2.0/UDP 64.7.99.27:5080;rport;branch=z9hG4bKp4X0yeSQQ1KDH
   Route: <sip:64.7.96.3;lr=on;ftag=eea75a70-f420-4416-8968-d6e5dfadb3f4-30174388;mp=yes;vsf=AAAAAAEACAB4AQYeDh55ABoYNy45Ni4z>
   Max-Forwards: 70
   From: <sip:16303437370@64.7.96.3>;tag=pj7BjD4ZFQ1DQ
   To: "Brent Sachnoff" <sip:7086872090@64.7.96.3>;tag=eea75a70-f420-4416-8968-d6e5dfadb3f4-30174388
   Call-ID: ffe3d80-7321e7b0-bfc3-6600740@64.7.96.6
   CSeq: 91140890 BYE
   User-Agent: FreeSWITCH
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
   Supported: timer, path, replaces
   Reason: Q.850;cause=16;text="NORMAL_CLEARING"
   Content-Length: 0
   X-RTP-Stat: PS=35,OS=6020,PR=56,OR=9632,PL=0,JI=0,DU=0,EN=G711U,DE=G711U
   
   ------------------------------------------------------------------------
2016-05-11 03:05:08.180958 [DEBUG] switch_core_state_machine.c:499 (sofia/internal/1001@73.72.98.76:5060) State Change CS_REPORTING -> CS_DESTROY
2016-05-11 03:05:08.180958 [DEBUG] switch_core_session.c:1646 Session 26 (sofia/internal/1001@73.72.98.76:5060) Locked, Waiting on external entities
2016-05-11 03:05:08.180958 [NOTICE] switch_core_session.c:1664 Session 26 (sofia/internal/1001@73.72.98.76:5060) Ended
2016-05-11 03:05:08.180958 [NOTICE] switch_core_session.c:1668 Close Channel sofia/internal/1001@73.72.98.76:5060 [CS_DESTROY]
2016-05-11 03:05:08.180958 [DEBUG] switch_core_state_machine.c:630 (sofia/internal/1001@73.72.98.76:5060) Running State Change CS_DESTROY
2016-05-11 03:05:08.180958 [DEBUG] switch_core_state_machine.c:640 (sofia/internal/1001@73.72.98.76:5060) State DESTROY
2016-05-11 03:05:08.180958 [DEBUG] mod_sofia.c:341 sofia/internal/1001@73.72.98.76:5060 SOFIA DESTROY
2016-05-11 03:05:08.180958 [DEBUG] switch_core_state_machine.c:111 sofia/internal/1001@73.72.98.76:5060 Standard DESTROY
2016-05-11 03:05:08.180958 [DEBUG] switch_core_state_machine.c:640 (sofia/internal/1001@73.72.98.76:5060) State DESTROY going to sleep
2016-05-11 03:05:08.180958 [DEBUG] switch_core_state_machine.c:672 Hangup Command with no Session lua(app.lua hangup):

2016-05-11 03:05:08.180958 [DEBUG] switch_core_state_machine.c:508 (sofia/external/7086872090@64.7.96.3) State Change CS_HANGUP -> CS_REPORTING
2016-05-11 03:05:08.180958 [DEBUG] switch_core_state_machine.c:473 (sofia/external/7086872090@64.7.96.3) Running State Change CS_REPORTING
2016-05-11 03:05:08.180958 [DEBUG] switch_core_state_machine.c:827 (sofia/external/7086872090@64.7.96.3) State REPORTING
recv 369 bytes from udp/[64.7.96.3]:5060 at 03:05:08.204640:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 64.7.99.27:5080;rport=5080;branch=z9hG4bKp4X0yeSQQ1KDH
   From: <sip:16303437370@64.7.96.3>;tag=pj7BjD4ZFQ1DQ
   To: "Brent Sachnoff" <sip:7086872090@64.7.96.3>;tag=eea75a70-f420-4416-8968-d6e5dfadb3f4-30174388
   Date: Wed, 11 May 2016 08:05:08 GMT
   Call-ID: ffe3d80-7321e7b0-bfc3-6600740@64.7.96.6
   CSeq: 91140890 BYE
   Content-Length: 0
   
   ------------------------------------------------------------------------
2016-05-11 03:05:08.260888 [DEBUG] switch_core_state_machine.c:104 sofia/external/7086872090@64.7.96.3 Standard REPORTING, cause: NORMAL_CLEARING
2016-05-11 03:05:08.260888 [DEBUG] switch_core_state_machine.c:827 (sofia/external/7086872090@64.7.96.3) State REPORTING going to sleep
2016-05-11 03:05:08.260888 [DEBUG] switch_core_state_machine.c:499 (sofia/external/7086872090@64.7.96.3) State Change CS_REPORTING -> CS_DESTROY
2016-05-11 03:05:08.260888 [DEBUG] switch_core_session.c:1646 Session 25 (sofia/external/7086872090@64.7.96.3) Locked, Waiting on external entities
2016-05-11 03:05:08.260888 [NOTICE] switch_core_session.c:1664 Session 25 (sofia/external/7086872090@64.7.96.3) Ended
2016-05-11 03:05:08.260888 [NOTICE] switch_core_session.c:1668 Close Channel sofia/external/7086872090@64.7.96.3 [CS_DESTROY]
2016-05-11 03:05:08.260888 [DEBUG] switch_core_state_machine.c:630 (sofia/external/7086872090@64.7.96.3) Running State Change CS_DESTROY
2016-05-11 03:05:08.260888 [DEBUG] switch_core_state_machine.c:640 (sofia/external/7086872090@64.7.96.3) State DESTROY
2016-05-11 03:05:08.260888 [DEBUG] mod_sofia.c:341 sofia/external/7086872090@64.7.96.3 SOFIA DESTROY
2016-05-11 03:05:08.260888 [DEBUG] switch_core_state_machine.c:111 sofia/external/7086872090@64.7.96.3 Standard DESTROY
2016-05-11 03:05:08.260888 [DEBUG] switch_core_state_machine.c:640 (sofia/external/7086872090@64.7.96.3) State DESTROY going to sleep
recv 850 bytes from udp/[73.72.98.76]:5060 at 03:05:17.622365:
   ------------------------------------------------------------------------
   REGISTER sip:besindustries.urbancom.net:5060 SIP/2.0
   Call-ID: 606bcf41@172.20.21.151
   Content-Length: 0
   CSeq: 16653 REGISTER
   From: <sip:1001@besindustries.urbancom.net>;tag=SP1f75f1c86bedf8eae
   Max-Forwards: 70
   To: <sip:1001@besindustries.urbancom.net>
   Via: SIP/2.0/UDP 73.72.98.76:5060;branch=z9hG4bK-eff76ad7;rport
   Authorization: Digest algorithm=MD5,nc=00000053,qop=auth,cnonce="5f3f9cfc",nonce="5d11441e-1749-11e6-b890-8dcc9e1d3d65",realm="besindustries.urbancom.net",response="dfcca36625722d7f5428a36c8c77d4fd",uri="sip:besindustries.urbancom.net:5060",username="1001"
   User-Agent: OBIHAI/OBi1062-5.0.0.3223
   Contact: <sip:1001@73.72.98.76:5060>;expires=60;+sip.instance="<urn:uuid:00000000-0000-0000-0000-9cadef700ee0>"
   Allow: ACK,BYE,CANCEL,INFO,INVITE,NOTIFY,OPTIONS,PRACK,REFER,UPDATE
   Supported: replaces, eventlist, record-aware
   
   ------------------------------------------------------------------------
send 546 bytes to udp/[73.72.98.76]:5060 at 03:05:17.636531:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 73.72.98.76:5060;branch=z9hG4bK-eff76ad7;rport=5060
   From: <sip:1001@besindustries.urbancom.net>;tag=SP1f75f1c86bedf8eae
   To: <sip:1001@besindustries.urbancom.net>;tag=5Svv49t2FD6gH
   Call-ID: 606bcf41@172.20.21.151
   CSeq: 16653 REGISTER
   Contact: <sip:1001@73.72.98.76:5060>;expires=60
   Date: Wed, 11 May 2016 08:05:17 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 850 bytes from udp/[73.72.98.76]:5060 at 03:05:47.650952:
   ------------------------------------------------------------------------
   REGISTER sip:besindustries.urbancom.net:5060 SIP/2.0
   Call-ID: 606bcf41@172.20.21.151
   Content-Length: 0
   CSeq: 16654 REGISTER
   From: <sip:1001@besindustries.urbancom.net>;tag=SP1f75f1c86bedf8eae
   Max-Forwards: 70
   To: <sip:1001@besindustries.urbancom.net>
   Via: SIP/2.0/UDP 73.72.98.76:5060;branch=z9hG4bK-67d716eb;rport
   Authorization: Digest algorithm=MD5,nc=00000054,qop=auth,cnonce="5f3f9cfc",nonce="5d11441e-1749-11e6-b890-8dcc9e1d3d65",realm="besindustries.urbancom.net",response="1cab14d805c3cd8691c80851cccc7622",uri="sip:besindustries.urbancom.net:5060",username="1001"
   User-Agent: OBIHAI/OBi1062-5.0.0.3223
   Contact: <sip:1001@73.72.98.76:5060>;expires=60;+sip.instance="<urn:uuid:00000000-0000-0000-0000-9cadef700ee0>"
   Allow: ACK,BYE,CANCEL,INFO,INVITE,NOTIFY,OPTIONS,PRACK,REFER,UPDATE
   Supported: replaces, eventlist, record-aware
   
   ------------------------------------------------------------------------
send 546 bytes to udp/[73.72.98.76]:5060 at 03:05:47.666108:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 73.72.98.76:5060;branch=z9hG4bK-67d716eb;rport=5060
   From: <sip:1001@besindustries.urbancom.net>;tag=SP1f75f1c86bedf8eae
   To: <sip:1001@besindustries.urbancom.net>;tag=62NN64B6cpv3c
   Call-ID: 606bcf41@172.20.21.151
   CSeq: 16654 REGISTER
   Contact: <sip:1001@73.72.98.76:5060>;expires=60
   Date: Wed, 11 May 2016 08:05:47 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@internal>