+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: 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" ;tag=eea75a70-f420-4416-8968-d6e5dfadb3f4-30174388 To: 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: Expires: 180 Allow-Events: presence, kpml Call-Info: ;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: From: "Brent Sachnoff" ;tag=eea75a70-f420-4416-8968-d6e5dfadb3f4-30174388 To: 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" ;tag=4g332eaZj4FyN To: Call-ID: e9030588-91f1-1234-b3a4-005056b9942b CSeq: 91140888 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: 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" ;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" ;tag=4g332eaZj4FyN To: ;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" ;tag=4g332eaZj4FyN To: ;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: 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: From: "Brent Sachnoff" ;tag=eea75a70-f420-4416-8968-d6e5dfadb3f4-30174388 To: ;tag=pj7BjD4ZFQ1DQ Call-ID: ffe3d80-7321e7b0-bfc3-6600740@64.7.96.6 CSeq: 101 INVITE Contact: 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" ;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" ;tag=4g332eaZj4FyN To: ;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: 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" ;tag=4g332eaZj4FyN To: ;tag=SP1935f3a4edaa5781a Call-ID: e9030588-91f1-1234-b3a4-005056b9942b CSeq: 91140888 ACK Contact: 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: From: "Brent Sachnoff" ;tag=eea75a70-f420-4416-8968-d6e5dfadb3f4-30174388 To: ;tag=pj7BjD4ZFQ1DQ Call-ID: ffe3d80-7321e7b0-bfc3-6600740@64.7.96.6 CSeq: 101 INVITE Contact: 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" ;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: 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" ;tag=eea75a70-f420-4416-8968-d6e5dfadb3f4-30174388 To: ;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: ;tag=SP1935f3a4edaa5781a Max-Forwards: 70 To: "Brent Sachnoff#Brent Sachnoff" ;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: ;tag=SP1935f3a4edaa5781a To: "Brent Sachnoff#Brent Sachnoff" ;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: Max-Forwards: 70 From: ;tag=pj7BjD4ZFQ1DQ To: "Brent Sachnoff" ;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: ;tag=pj7BjD4ZFQ1DQ To: "Brent Sachnoff" ;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: ;tag=SP1f75f1c86bedf8eae Max-Forwards: 70 To: 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: ;expires=60;+sip.instance="" 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: ;tag=SP1f75f1c86bedf8eae To: ;tag=5Svv49t2FD6gH Call-ID: 606bcf41@172.20.21.151 CSeq: 16653 REGISTER Contact: ;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: ;tag=SP1f75f1c86bedf8eae Max-Forwards: 70 To: 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: ;expires=60;+sip.instance="" 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: ;tag=SP1f75f1c86bedf8eae To: ;tag=62NN64B6cpv3c Call-ID: 606bcf41@172.20.21.151 CSeq: 16654 REGISTER Contact: ;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>