[This app Best viewed at 160x60 or more..]
+OK log level  [7]
2018-08-29 13:24:48.295933 [NOTICE] switch_channel.c:1104 New Channel sofia/external/5195752944@208.89.129.46 [be373d2a-b115-4ab2-8037-5a7b62a392cc]
2018-08-29 13:24:48.295933 [DEBUG] switch_core_state_machine.c:584 (sofia/external/5195752944@208.89.129.46) Running State Change CS_NEW (Cur 1 Tot 46967)
2018-08-29 13:24:48.295933 [DEBUG] sofia.c:9825 sofia/external/5195752944@208.89.129.46 receiving invite from 208.89.129.46:5060 version: 1.6.16  64bit
2018-08-29 13:24:48.295933 [DEBUG] sofia.c:7048 Channel sofia/external/5195752944@208.89.129.46 entering state [received][100]
2018-08-29 13:24:48.295933 [DEBUG] sofia.c:7058 Remote SDP:
v=0
o=IRISMSC8 2260163627 2260163627 IN IP4 208.89.129.46
s=sip call
c=IN IP4 208.89.128.69
t=0 0
m=audio 59728 RTP/AVP 0 8 18 9 101
a=rtpmap:101 telephone-event/8000
a=ptime:20

2018-08-29 13:24:48.295933 [DEBUG] sofia.c:7450 (sofia/external/5195752944@208.89.129.46) State Change CS_NEW -> CS_INIT
2018-08-29 13:24:48.295933 [DEBUG] switch_core_state_machine.c:603 (sofia/external/5195752944@208.89.129.46) State NEW
2018-08-29 13:24:48.295933 [DEBUG] switch_core_state_machine.c:584 (sofia/external/5195752944@208.89.129.46) Running State Change CS_INIT (Cur 1 Tot 46967)
2018-08-29 13:24:48.295933 [DEBUG] switch_core_state_machine.c:627 (sofia/external/5195752944@208.89.129.46) State INIT
2018-08-29 13:24:48.295933 [DEBUG] mod_sofia.c:90 sofia/external/5195752944@208.89.129.46 SOFIA INIT
2018-08-29 13:24:48.295933 [DEBUG] switch_core_state_machine.c:40 sofia/external/5195752944@208.89.129.46 Standard INIT
2018-08-29 13:24:48.295933 [DEBUG] switch_core_state_machine.c:48 (sofia/external/5195752944@208.89.129.46) State Change CS_INIT -> CS_ROUTING
2018-08-29 13:24:48.295933 [DEBUG] switch_core_state_machine.c:627 (sofia/external/5195752944@208.89.129.46) State INIT going to sleep
2018-08-29 13:24:48.295933 [DEBUG] switch_core_state_machine.c:584 (sofia/external/5195752944@208.89.129.46) Running State Change CS_ROUTING (Cur 1 Tot 46967)
2018-08-29 13:24:48.295933 [DEBUG] switch_channel.c:2249 (sofia/external/5195752944@208.89.129.46) Callstate Change DOWN -> RINGING
2018-08-29 13:24:48.295933 [DEBUG] switch_core_state_machine.c:643 (sofia/external/5195752944@208.89.129.46) State ROUTING
2018-08-29 13:24:48.295933 [DEBUG] mod_sofia.c:143 sofia/external/5195752944@208.89.129.46 SOFIA ROUTING
2018-08-29 13:24:48.295933 [DEBUG] switch_core_state_machine.c:236 sofia/external/5195752944@208.89.129.46 Standard ROUTING
2018-08-29 13:24:48.295933 [INFO] mod_dialplan_xml.c:637 Processing 5195752944 <5195752944>->15198846700 in context public
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->CNAM] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [CNAM] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [CNAM] destination_number(15198846700) =~ /\d{10,}/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Action set(call_direction=inbound) INLINE
EXECUTE sofia/external/5195752944@208.89.129.46 set(call_direction=inbound)
2018-08-29 13:24:48.315933 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [call_direction]=[inbound]
Dialplan: sofia/external/5195752944@208.89.129.46 Action set(domain_name=208.89.129.46) INLINE
EXECUTE sofia/external/5195752944@208.89.129.46 set(domain_name=208.89.129.46)
2018-08-29 13:24:48.315933 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [domain_name]=[208.89.129.46]
Dialplan: sofia/external/5195752944@208.89.129.46 Action set(call_direction=inbound) 
Dialplan: sofia/external/5195752944@208.89.129.46 Action export(effective_caller_id_name=${cidlookup(${caller_id_number})}) INLINE
EXECUTE sofia/external/5195752944@208.89.129.46 export(effective_caller_id_name=Adrien Alexson)
2018-08-29 13:24:48.315933 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [effective_caller_id_name]=[Adrien Alexson]
Dialplan: sofia/external/5195752944@208.89.129.46 Action export(caller_id_name=${cidlookup(${caller_id_number})}) 
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->CNAM] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [CNAM] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [CNAM] destination_number(15198846700) =~ /(\d{10,})/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Action set(call_direction=inbound) INLINE
EXECUTE sofia/external/5195752944@208.89.129.46 set(call_direction=inbound)
2018-08-29 13:24:48.315933 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [call_direction]=[inbound]
Dialplan: sofia/external/5195752944@208.89.129.46 Action set(domain_name=208.89.129.46) INLINE
EXECUTE sofia/external/5195752944@208.89.129.46 set(domain_name=208.89.129.46)
2018-08-29 13:24:48.315933 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [domain_name]=[208.89.129.46]
Dialplan: sofia/external/5195752944@208.89.129.46 Action set(effective_caller_id_name=${cidlookup(${caller_id_number})}) INLINE
EXECUTE sofia/external/5195752944@208.89.129.46 set(effective_caller_id_name=Adrien Alexson)
2018-08-29 13:24:48.315933 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [effective_caller_id_name]=[Adrien Alexson]
Dialplan: sofia/external/5195752944@208.89.129.46 Action log(test099-${caller_id_name}) 
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->16138000576] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [16138000576] destination_number(15198846700) =~ /^1?(6138000576)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->2262435236] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [2262435236] destination_number(15198846700) =~ /^(2262435236)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->2262435238] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [2262435238] destination_number(15198846700) =~ /^(2262435238)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->2266400027] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [2266400027] destination_number(15198846700) =~ /^(2266400027)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->7059960303] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [7059960303] destination_number(15198846700) =~ /^(7059960303)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->5198846700-Cell] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [5198846700-Cell] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [5198846700-Cell] caller_id_number(5195752944) =~ /2267920807|2268081547|5198846700/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->AA-DISA] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [AA-DISA] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [AA-DISA] caller_id_number(5195752944) =~ /5195752944|2262204796/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [AA-DISA] destination_number(15198846700) =~ /^\+?1?(4167577930)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->RAJA-DISA] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [RAJA-DISA] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [RAJA-DISA] caller_id_number(5195752944) =~ /5195019008|4162006746|5193562294|5192910677|5192911777/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->+12262435231] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [+12262435231] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [+12262435231] destination_number(15198846700) =~ /^\+?1?(2262435231)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->+12262435232] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [+12262435232] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [+12262435232] destination_number(15198846700) =~ /^\+?1?(2262435232)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->+12264764502] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [+12264764502] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [+12264764502] destination_number(15198846700) =~ /^\+?1?(2264764502)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->+14167577930] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [+14167577930] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [+14167577930] destination_number(15198846700) =~ /^\+?1?(4167577930)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->+14169972944] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [+14169972944] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [+14169972944] destination_number(15198846700) =~ /^\+?1?(4169972944)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->+15197419672] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [+15197419672] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [+15197419672] destination_number(15198846700) =~ /^\+?1?(5197419672)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->+15197419679] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [+15197419679] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [+15197419679] destination_number(15198846700) =~ /^\+?1?(5197419679)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->+18445712124] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [+18445712124] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [+18445712124] destination_number(15198846700) =~ /^\+?1?(8445712124)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->+2013666069] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [+2013666069] destination_number(15198846700) =~ /^\+?1?(2013666069)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->+2262413076] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [+2262413076] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [+2262413076] destination_number(15198846700) =~ /^\+?1?(2262413076)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->+2264762186] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [+2264762186] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [+2264762186] destination_number(15198846700) =~ /^\+?1?(2264762186)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->+4162598662] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [+4162598662] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [+4162598662] destination_number(15198846700) =~ /^\+?1?(4162598662)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->+4163688900] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [+4163688900] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [+4163688900] destination_number(15198846700) =~ /^\+?1?(4163688900)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->+5193562296] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [+5193562296] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [+5193562296] destination_number(15198846700) =~ /^\+?1?(5193562296)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->+5193569008] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [+5193569008] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [+5193569008] destination_number(15198846700) =~ /^\+?1?(5193569008)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->+5193569041] continue=false
2018-08-29 13:24:48.315933 [NOTICE] mod_logfile.c:213 New log started.
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [+5193569041] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [+5193569041] destination_number(15198846700) =~ /^\+?1?(5193569041)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->+5196511551] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [+5196511551] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [+5196511551] destination_number(15198846700) =~ /^\+?1?(5196511551)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->+5196672007] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [+5196672007] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [+5196672007] destination_number(15198846700) =~ /\+?1?5196672007/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->+7053429697] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [+7053429697] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [+7053429697] destination_number(15198846700) =~ /^\+?1?(7053429697)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->+7059960373] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [+7059960373] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [+7059960373] destination_number(15198846700) =~ /^\+?1?(7059960373)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->12262413076] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [12262413076] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [12262413076] destination_number(15198846700) =~ /^\+?1?1(2262413076)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->12267703634] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [12267703634] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [12267703634] destination_number(15198846700) =~ /^\+?1?(2267703634)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->12267800390] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [12267800390] destination_number(15198846700) =~ /^\+?1?(2267800390)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->15199421101] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [15199421101] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [15199421101] destination_number(15198846700) =~ /^\+?1?(5199421101)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->16476991518] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [16476991518] destination_number(15198846700) =~ /^\+?1?(6476991518)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->17059961737] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [17059961737] destination_number(15198846700) =~ /^\+?1?(17059961737)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->18002658900] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [18002658900] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [18002658900] destination_number(15198846700) =~ /^\+?1?(8002658900)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->18184899728] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [18184899728] destination_number(15198846700) =~ /^\+?1?(8184899728)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->2264761354] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [2264761354] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [2264761354] destination_number(15198846700) =~ /^\+?1?(2264761354)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->5193562294] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [5193562294] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [5193562294] destination_number(15198846700) =~ /^\+?1?(5193562294)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->5198846097] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [5198846097] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [5198846097] destination_number(15198846700) =~ /^\+?1?(5198846097)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [public->5198846700] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [5198846700] context(public) =~ /public/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [5198846700] destination_number(15198846700) =~ /^\+?1?(5198846700)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Action set(call_direction=inbound) INLINE
EXECUTE sofia/external/5195752944@208.89.129.46 set(call_direction=inbound)
2018-08-29 13:24:48.315933 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [call_direction]=[inbound]
Dialplan: sofia/external/5195752944@208.89.129.46 Action set(domain_uuid=64b5d36d-f8e3-459d-80fd-6f1069aaee4c) INLINE
EXECUTE sofia/external/5195752944@208.89.129.46 set(domain_uuid=64b5d36d-f8e3-459d-80fd-6f1069aaee4c)
2018-08-29 13:24:48.315933 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [domain_uuid]=[64b5d36d-f8e3-459d-80fd-6f1069aaee4c]
Dialplan: sofia/external/5195752944@208.89.129.46 Action set(domain_name=thecarmel.uphone.ca) INLINE
EXECUTE sofia/external/5195752944@208.89.129.46 set(domain_name=thecarmel.uphone.ca)
2018-08-29 13:24:48.315933 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [domain_name]=[thecarmel.uphone.ca]
Dialplan: sofia/external/5195752944@208.89.129.46 Action set(accountcode=thecarmel.uphone.ca) 
Dialplan: sofia/external/5195752944@208.89.129.46 Action set(call_direction=inbound) 
Dialplan: sofia/external/5195752944@208.89.129.46 Action transfer(7000 XML thecarmel.uphone.ca) 
2018-08-29 13:24:48.315933 [DEBUG] switch_core_state_machine.c:286 (sofia/external/5195752944@208.89.129.46) State Change CS_ROUTING -> CS_EXECUTE
2018-08-29 13:24:48.315933 [DEBUG] switch_core_state_machine.c:643 (sofia/external/5195752944@208.89.129.46) State ROUTING going to sleep
2018-08-29 13:24:48.315933 [DEBUG] switch_core_state_machine.c:584 (sofia/external/5195752944@208.89.129.46) Running State Change CS_EXECUTE (Cur 1 Tot 46967)
2018-08-29 13:24:48.315933 [DEBUG] switch_core_state_machine.c:650 (sofia/external/5195752944@208.89.129.46) State EXECUTE
2018-08-29 13:24:48.315933 [DEBUG] mod_sofia.c:198 sofia/external/5195752944@208.89.129.46 SOFIA EXECUTE
2018-08-29 13:24:48.315933 [DEBUG] switch_core_state_machine.c:328 sofia/external/5195752944@208.89.129.46 Standard EXECUTE
EXECUTE sofia/external/5195752944@208.89.129.46 set(call_direction=inbound)
2018-08-29 13:24:48.315933 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [call_direction]=[inbound]
EXECUTE sofia/external/5195752944@208.89.129.46 export(caller_id_name=Adrien Alexson)
2018-08-29 13:24:48.315933 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [caller_id_name]=[Adrien Alexson]
EXECUTE sofia/external/5195752944@208.89.129.46 log(test099-Adrien Alexson)
2018-08-29 13:24:48.315933 [DEBUG] mod_dptools.c:1724 Alexson
EXECUTE sofia/external/5195752944@208.89.129.46 set(accountcode=thecarmel.uphone.ca)
2018-08-29 13:24:48.315933 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [accountcode]=[thecarmel.uphone.ca]
EXECUTE sofia/external/5195752944@208.89.129.46 set(call_direction=inbound)
2018-08-29 13:24:48.315933 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [call_direction]=[inbound]
EXECUTE sofia/external/5195752944@208.89.129.46 transfer(7000 XML thecarmel.uphone.ca)
2018-08-29 13:24:48.315933 [DEBUG] switch_ivr.c:2165 (sofia/external/5195752944@208.89.129.46) State Change CS_EXECUTE -> CS_ROUTING
2018-08-29 13:24:48.315933 [NOTICE] switch_ivr.c:2172 Transfer sofia/external/5195752944@208.89.129.46 to XML[7000@thecarmel.uphone.ca]
2018-08-29 13:24:48.315933 [DEBUG] switch_core_state_machine.c:650 (sofia/external/5195752944@208.89.129.46) State EXECUTE going to sleep
2018-08-29 13:24:48.315933 [DEBUG] switch_core_state_machine.c:584 (sofia/external/5195752944@208.89.129.46) Running State Change CS_ROUTING (Cur 1 Tot 46967)
2018-08-29 13:24:48.315933 [DEBUG] switch_core_state_machine.c:643 (sofia/external/5195752944@208.89.129.46) State ROUTING
2018-08-29 13:24:48.315933 [DEBUG] mod_sofia.c:143 sofia/external/5195752944@208.89.129.46 SOFIA ROUTING
2018-08-29 13:24:48.315933 [DEBUG] switch_core_state_machine.c:236 sofia/external/5195752944@208.89.129.46 Standard ROUTING
2018-08-29 13:24:48.315933 [INFO] mod_dialplan_xml.c:637 Processing 5195752944 <5195752944>->7000 in context thecarmel.uphone.ca
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->user_exists] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [user_exists] () =~ // break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
2018-08-29 13:24:48.335925 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f67a409d500 Connected.
2018-08-29 13:24:48.335925 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f67a409d500 released.
EXECUTE sofia/external/5195752944@208.89.129.46 set(user_exists=false)
2018-08-29 13:24:48.335925 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [user_exists]=[false]
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->call-direction] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [call-direction] ${call_direction}(inbound) =~ /^(inbound|outbound|local)$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->variables] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [variables] () =~ // break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Action export(origination_callee_id_name=${destination_number}) 
Dialplan: sofia/external/5195752944@208.89.129.46 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) 
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->call_block] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [call_block] ${call_blocked}() =~ /^true$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 ANTI-Action lua(app.lua call_block) 
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->user_record] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [user_record] () =~ // break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Action set(user_record=${user_data ${destination_number}@${domain_name} var user_record}) INLINE
2018-08-29 13:24:48.335925 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f67a409d500 Connected.
2018-08-29 13:24:48.335925 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f67a409d500 released.
2018-08-29 13:24:48.335925 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f67a409d500 Connected.
2018-08-29 13:24:48.355928 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f67a409d500 released.
EXECUTE sofia/external/5195752944@208.89.129.46 set(user_record=)
2018-08-29 13:24:48.355928 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [user_record]=[UNDEF]
Dialplan: sofia/external/5195752944@208.89.129.46 Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
2018-08-29 13:24:48.355928 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f67a409d500 Connected.
2018-08-29 13:24:48.355928 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f67a409d500 released.
EXECUTE sofia/external/5195752944@208.89.129.46 set(from_user_exists=false)
2018-08-29 13:24:48.355928 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [from_user_exists]=[false]
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [user_record] ${call_direction}(inbound) =~ /^inbound$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^outbound$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^local$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [user_record] ${call_direction}(inbound) =~ /^inbound$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^outbound$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^local$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->redial] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [redial] destination_number(7000) =~ /^(redial|\*870)$/ break=on-true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [redial] () =~ // break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) 
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->speed_dial] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [speed_dial] destination_number(7000) =~ /^\*0(.*)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->911-Iris] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [911-Iris] destination_number(7000) =~ /^911$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->911-Iris-copy] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [911-Iris-copy] destination_number(7000) =~ /^911$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->922-test] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [922-test] destination_number(7000) =~ /^922$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->country_variables] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [country_variables] () =~ // break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Action set(toll_allow=all) INLINE
EXECUTE sofia/external/5195752944@208.89.129.46 set(toll_allow=all)
2018-08-29 13:24:48.355928 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [toll_allow]=[all]
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->outbound_call_restriction] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [outbound_call_restriction] ${call_direction}(inbound) =~ /^(outbound)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->local_dids] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [local_dids] destination_number(7000) =~ /^\+?1?(\d{10})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->CanadaCalling] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [CanadaCalling] ${toll_allow}(all) =~ /all|canada|northamerica/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [CanadaCalling] destination_number(7000) =~ /^\+?1?((204|226|236|249|250|289|306|343|343|365|403|416|418|431|437|438|450|506|514|519|548|579|581|587|604|613|613|639|647|705|709|778|780|782|782|807|819|825|867|867|867|873|902|902|905)[2-9]\d{6})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->US_Calling] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [US_Calling] ${toll_allow}(all) =~ /all|northamerica|unitedstates/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [US_Calling] destination_number(7000) =~ /^\+?1?((201|202|203|205|206|207|208|209|210|212|213|214|215|216|217|218|219|220|224|225|227|228|229|231|234|239|240|248|251|252|253|254|256|260|262|267|269|270|272|274|276|281|283|301|302|303|304|305|307|308|309|310|312|313|314|315|316|317|318|319|320|321|323|325|327|330|331|332|334|336|337|339|346|347|351|352|360|361|364|380|385|386|401|402|404|405|406|407|408|409|410|412|413|414|415|417|419|423|424|425|430|432|434|435|440|442|443|447|458|463|464|469|470|475|478|479|480|484|501|502|503|504|505|507|508|509|510|512|513|515|516|517|518|520|530|531|534|539|540|541|551|557|559|561|562|563|564|567|570|571|573|574|575|580|585|586|601|602|603|605|606|607|608|609|610|612|614|615|616|617|618|619|620|623|626|628|629|630|631|636|641|646|650|651|657|659|660|661|662|667|669|678|679|680|681|682|689|701|702|703|704|706|707|708|712|713|714|715|716|717|718|719|720|724|725|726|727|730|731|732|734|737|740|743|747|754|757|760|762|763|765|769|770|772|773|774|775|779|781|785|786|801|802|803|804|805|806|808|810|812|813|814|815|816|817|818|828|830|831|832|838|843|845|847|848|850|854|856|857|858|859|860|862|863|864|865|870|872|878|901|903|904|906|907|908|909|910|912|913|914|915|916|917|918|919|920|925|928|929|930|931|934|936|937|938|940|941|947|949|951|952|954|956|959|970|971|972|973|975|978|979|980|984|985|986|989)[2-9]\d{6})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->Toll-Free_Calling] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [Toll-Free_Calling] destination_number(7000) =~ /^\+?1?(8(00|33|44|55|66|77|88)[2-9]\d{6})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->310-Iris] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [310-Iris] destination_number(7000) =~ /^310(\d{4})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->Anguilla] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [Anguilla] destination_number(7000) =~ /^\+?1?(264[2-9]\d{6})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->Bermuda] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [Bermuda] ${toll_allow}(all) =~ /all|northamerica|bermuda/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [Bermuda] destination_number(7000) =~ /^\+?1?(441[2-9]\d{6})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->Jamaica] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [Jamaica] destination_number(7000) =~ /^\+?1?(876[2-9]\d{6})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->agent_status] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [agent_status] destination_number(7000) =~ /^\*22$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->International-LCR] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [International-LCR] ${toll_allow}(all) =~ /all|international|CAUSInternational/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [International-LCR] destination_number(7000) =~ /^(011|00)(\d{9,17})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->sbc.voxbeam.com.International-copy] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [sbc.voxbeam.com.International-copy] destination_number(7000) =~ /^(011|00)(\d{9,17})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->agent_status_id] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [agent_status_id] destination_number(7000) =~ /^\*23$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->group-intercept] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [group-intercept] destination_number(7000) =~ /^\*8$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->page-extension] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [page-extension] destination_number(7000) =~ /^\*8(\d{2,7})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->eavesdrop] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [eavesdrop] destination_number(7000) =~ /^\*33(\d{2,7})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->call_privacy] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [call_privacy] destination_number(7000) =~ /^\*67(\d+)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->call_return] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [call_return] destination_number(7000) =~ /^\*69$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->extension_queue] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [extension_queue] destination_number(7000) =~ /^\*800(.*)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->intercept-ext] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [intercept-ext] destination_number(7000) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->intercept-ext-polycom] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [intercept-ext-polycom] destination_number(7000) =~ /^\*97(\d+)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->dx] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [dx] destination_number(7000) =~ /^dx$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->no-ring] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [no-ring] destination_number(7000) =~ /^4000$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->att_xfer] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [att_xfer] destination_number(7000) =~ /^att_xfer$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->Carmel-Fax] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [Carmel-Fax] destination_number(7000) =~ /^125$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->extension-to-voicemail] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [extension-to-voicemail] ${user_exists}(false) =~ /^true$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->send_to_voicemail] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [send_to_voicemail] destination_number(7000) =~ /^\*99(\d{2,10})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->vmain] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [vmain] destination_number(7000) =~ /^vmain$|^\*4000$|^\*98$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->xfer_vm] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [xfer_vm] destination_number(7000) =~ /^xfer_vm$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->is_transfer] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [is_transfer] destination_number(7000) =~ /^is_transfer$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->vmain_user] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [vmain_user] destination_number(7000) =~ /^\*97$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->allphones] continue=
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [allphones] destination_number(7000) =~ /^4200$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->private] continue=
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [private] destination_number(7000) =~ /^\*7000$/ break=on-true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [private] destination_number(7000) =~ /^7000$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Action set(call_flow_uuid=0d092c7d-7540-4425-bc1c-da2489e2de39) 
Dialplan: sofia/external/5195752944@208.89.129.46 Action lua(call_flow.lua) 
2018-08-29 13:24:48.355928 [DEBUG] switch_core_state_machine.c:286 (sofia/external/5195752944@208.89.129.46) State Change CS_ROUTING -> CS_EXECUTE
2018-08-29 13:24:48.355928 [DEBUG] switch_core_state_machine.c:643 (sofia/external/5195752944@208.89.129.46) State ROUTING going to sleep
2018-08-29 13:24:48.355928 [DEBUG] switch_core_state_machine.c:584 (sofia/external/5195752944@208.89.129.46) Running State Change CS_EXECUTE (Cur 1 Tot 46967)
2018-08-29 13:24:48.355928 [DEBUG] switch_core_state_machine.c:650 (sofia/external/5195752944@208.89.129.46) State EXECUTE
2018-08-29 13:24:48.355928 [DEBUG] mod_sofia.c:198 sofia/external/5195752944@208.89.129.46 SOFIA EXECUTE
2018-08-29 13:24:48.355928 [DEBUG] switch_core_state_machine.c:328 sofia/external/5195752944@208.89.129.46 Standard EXECUTE
EXECUTE sofia/external/5195752944@208.89.129.46 export(origination_callee_id_name=7000)
2018-08-29 13:24:48.355928 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [origination_callee_id_name]=[7000]
EXECUTE sofia/external/5195752944@208.89.129.46 set(RFC2822_DATE=Wed, 29 Aug 2018 13:24:48 -0400)
2018-08-29 13:24:48.355928 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [RFC2822_DATE]=[Wed, 29 Aug 2018 13:24:48 -0400]
EXECUTE sofia/external/5195752944@208.89.129.46 lua(app.lua call_block)
2018-08-29 13:24:48.355928 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('call_block', '')
2018-08-29 13:24:48.355928 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f67a409d500 Connected.
2018-08-29 13:24:48.355928 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f67a409d500 released.
2018-08-29 13:24:48.355928 [DEBUG] switch_cpp.cpp:1112 sofia/external/5195752944@208.89.129.46 destroy/unlink session from object
EXECUTE sofia/external/5195752944@208.89.129.46 hash(insert/thecarmel.uphone.ca-last_dial/5195752944/7000)
EXECUTE sofia/external/5195752944@208.89.129.46 set(call_flow_uuid=0d092c7d-7540-4425-bc1c-da2489e2de39)
2018-08-29 13:24:48.355928 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [call_flow_uuid]=[0d092c7d-7540-4425-bc1c-da2489e2de39]
EXECUTE sofia/external/5195752944@208.89.129.46 lua(call_flow.lua)
2018-08-29 13:24:48.355928 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f67a409d500 Connected.
2018-08-29 13:24:48.375932 [NOTICE] switch_cpp.cpp:1365 [call_flow] execute transfer 4000 XML thecarmel.uphone.ca
EXECUTE sofia/external/5195752944@208.89.129.46 transfer(4000 XML thecarmel.uphone.ca)
2018-08-29 13:24:48.375932 [DEBUG] switch_ivr.c:2165 (sofia/external/5195752944@208.89.129.46) State Change CS_EXECUTE -> CS_ROUTING
2018-08-29 13:24:48.375932 [NOTICE] switch_ivr.c:2172 Transfer sofia/external/5195752944@208.89.129.46 to XML[4000@thecarmel.uphone.ca]
2018-08-29 13:24:48.375932 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f67a409d500 released.
2018-08-29 13:24:48.375932 [DEBUG] switch_cpp.cpp:1112 sofia/external/5195752944@208.89.129.46 destroy/unlink session from object
2018-08-29 13:24:48.375932 [DEBUG] switch_core_state_machine.c:650 (sofia/external/5195752944@208.89.129.46) State EXECUTE going to sleep
2018-08-29 13:24:48.375932 [DEBUG] switch_core_state_machine.c:584 (sofia/external/5195752944@208.89.129.46) Running State Change CS_ROUTING (Cur 1 Tot 46967)
2018-08-29 13:24:48.375932 [DEBUG] switch_core_state_machine.c:643 (sofia/external/5195752944@208.89.129.46) State ROUTING
2018-08-29 13:24:48.375932 [DEBUG] mod_sofia.c:143 sofia/external/5195752944@208.89.129.46 SOFIA ROUTING
2018-08-29 13:24:48.375932 [DEBUG] switch_core_state_machine.c:236 sofia/external/5195752944@208.89.129.46 Standard ROUTING
2018-08-29 13:24:48.375932 [INFO] mod_dialplan_xml.c:637 Processing 5195752944 <5195752944>->4000 in context thecarmel.uphone.ca
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->user_exists] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [user_exists] () =~ // break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
2018-08-29 13:24:48.375932 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f67a409d500 Connected.
2018-08-29 13:24:48.375932 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f67a409d500 released.
EXECUTE sofia/external/5195752944@208.89.129.46 set(user_exists=false)
2018-08-29 13:24:48.375932 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [user_exists]=[false]
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->call-direction] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [call-direction] ${call_direction}(inbound) =~ /^(inbound|outbound|local)$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->variables] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [variables] () =~ // break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Action export(origination_callee_id_name=${destination_number}) 
Dialplan: sofia/external/5195752944@208.89.129.46 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) 
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->call_block] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [call_block] ${call_blocked}() =~ /^true$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 ANTI-Action lua(app.lua call_block) 
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->user_record] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [user_record] () =~ // break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Action set(user_record=${user_data ${destination_number}@${domain_name} var user_record}) INLINE
2018-08-29 13:24:48.375932 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f67a409d500 Connected.
2018-08-29 13:24:48.395924 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f67a409d500 released.
2018-08-29 13:24:48.395924 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f67a409d500 Connected.
2018-08-29 13:24:48.395924 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f67a409d500 released.
EXECUTE sofia/external/5195752944@208.89.129.46 set(user_record=)
2018-08-29 13:24:48.395924 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [user_record]=[UNDEF]
Dialplan: sofia/external/5195752944@208.89.129.46 Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
2018-08-29 13:24:48.395924 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f67a409d500 Connected.
2018-08-29 13:24:48.395924 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f67a409d500 released.
EXECUTE sofia/external/5195752944@208.89.129.46 set(from_user_exists=false)
2018-08-29 13:24:48.395924 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [from_user_exists]=[false]
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [user_record] ${call_direction}(inbound) =~ /^inbound$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^outbound$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^local$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [user_record] ${call_direction}(inbound) =~ /^inbound$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^outbound$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^local$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->redial] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [redial] destination_number(4000) =~ /^(redial|\*870)$/ break=on-true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [redial] () =~ // break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) 
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->speed_dial] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [speed_dial] destination_number(4000) =~ /^\*0(.*)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->911-Iris] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [911-Iris] destination_number(4000) =~ /^911$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->911-Iris-copy] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [911-Iris-copy] destination_number(4000) =~ /^911$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->922-test] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [922-test] destination_number(4000) =~ /^922$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->country_variables] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [country_variables] () =~ // break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Action set(toll_allow=all) INLINE
EXECUTE sofia/external/5195752944@208.89.129.46 set(toll_allow=all)
2018-08-29 13:24:48.395924 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [toll_allow]=[all]
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->outbound_call_restriction] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [outbound_call_restriction] ${call_direction}(inbound) =~ /^(outbound)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->local_dids] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [local_dids] destination_number(4000) =~ /^\+?1?(\d{10})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->CanadaCalling] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [CanadaCalling] ${toll_allow}(all) =~ /all|canada|northamerica/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [CanadaCalling] destination_number(4000) =~ /^\+?1?((204|226|236|249|250|289|306|343|343|365|403|416|418|431|437|438|450|506|514|519|548|579|581|587|604|613|613|639|647|705|709|778|780|782|782|807|819|825|867|867|867|873|902|902|905)[2-9]\d{6})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->US_Calling] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [US_Calling] ${toll_allow}(all) =~ /all|northamerica|unitedstates/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [US_Calling] destination_number(4000) =~ /^\+?1?((201|202|203|205|206|207|208|209|210|212|213|214|215|216|217|218|219|220|224|225|227|228|229|231|234|239|240|248|251|252|253|254|256|260|262|267|269|270|272|274|276|281|283|301|302|303|304|305|307|308|309|310|312|313|314|315|316|317|318|319|320|321|323|325|327|330|331|332|334|336|337|339|346|347|351|352|360|361|364|380|385|386|401|402|404|405|406|407|408|409|410|412|413|414|415|417|419|423|424|425|430|432|434|435|440|442|443|447|458|463|464|469|470|475|478|479|480|484|501|502|503|504|505|507|508|509|510|512|513|515|516|517|518|520|530|531|534|539|540|541|551|557|559|561|562|563|564|567|570|571|573|574|575|580|585|586|601|602|603|605|606|607|608|609|610|612|614|615|616|617|618|619|620|623|626|628|629|630|631|636|641|646|650|651|657|659|660|661|662|667|669|678|679|680|681|682|689|701|702|703|704|706|707|708|712|713|714|715|716|717|718|719|720|724|725|726|727|730|731|732|734|737|740|743|747|754|757|760|762|763|765|769|770|772|773|774|775|779|781|785|786|801|802|803|804|805|806|808|810|812|813|814|815|816|817|818|828|830|831|832|838|843|845|847|848|850|854|856|857|858|859|860|862|863|864|865|870|872|878|901|903|904|906|907|908|909|910|912|913|914|915|916|917|918|919|920|925|928|929|930|931|934|936|937|938|940|941|947|949|951|952|954|956|959|970|971|972|973|975|978|979|980|984|985|986|989)[2-9]\d{6})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->Toll-Free_Calling] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [Toll-Free_Calling] destination_number(4000) =~ /^\+?1?(8(00|33|44|55|66|77|88)[2-9]\d{6})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->310-Iris] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [310-Iris] destination_number(4000) =~ /^310(\d{4})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->Anguilla] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [Anguilla] destination_number(4000) =~ /^\+?1?(264[2-9]\d{6})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->Bermuda] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [Bermuda] ${toll_allow}(all) =~ /all|northamerica|bermuda/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [Bermuda] destination_number(4000) =~ /^\+?1?(441[2-9]\d{6})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->Jamaica] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [Jamaica] destination_number(4000) =~ /^\+?1?(876[2-9]\d{6})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->agent_status] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [agent_status] destination_number(4000) =~ /^\*22$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->International-LCR] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [International-LCR] ${toll_allow}(all) =~ /all|international|CAUSInternational/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [International-LCR] destination_number(4000) =~ /^(011|00)(\d{9,17})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->sbc.voxbeam.com.International-copy] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [sbc.voxbeam.com.International-copy] destination_number(4000) =~ /^(011|00)(\d{9,17})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->agent_status_id] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [agent_status_id] destination_number(4000) =~ /^\*23$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->group-intercept] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [group-intercept] destination_number(4000) =~ /^\*8$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->page-extension] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [page-extension] destination_number(4000) =~ /^\*8(\d{2,7})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->eavesdrop] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [eavesdrop] destination_number(4000) =~ /^\*33(\d{2,7})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->call_privacy] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [call_privacy] destination_number(4000) =~ /^\*67(\d+)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->call_return] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [call_return] destination_number(4000) =~ /^\*69$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->extension_queue] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [extension_queue] destination_number(4000) =~ /^\*800(.*)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->intercept-ext] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [intercept-ext] destination_number(4000) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->intercept-ext-polycom] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [intercept-ext-polycom] destination_number(4000) =~ /^\*97(\d+)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->dx] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [dx] destination_number(4000) =~ /^dx$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->no-ring] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [no-ring] destination_number(4000) =~ /^4000$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Date/TimeMatch (FAIL) [no-ring] break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [no-ring] destination_number(4000) =~ /^4000$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Date/TimeMatch (FAIL) [no-ring] break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [no-ring] destination_number(4000) =~ /^4000$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Date/TimeMatch (FAIL) [no-ring] break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [no-ring] destination_number(4000) =~ /^4000$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Date/TimeMatch (FAIL) [no-ring] break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [no-ring] destination_number(4000) =~ /^4000$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Date/TimeMatch (FAIL) [no-ring] break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [no-ring] destination_number(4000) =~ /^4000$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Action transfer(4200 XML thecarmel.uphone.ca) 
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->att_xfer] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [att_xfer] destination_number(4000) =~ /^att_xfer$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->Carmel-Fax] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [Carmel-Fax] destination_number(4000) =~ /^125$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->extension-to-voicemail] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [extension-to-voicemail] ${user_exists}(false) =~ /^true$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->send_to_voicemail] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [send_to_voicemail] destination_number(4000) =~ /^\*99(\d{2,10})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->vmain] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [vmain] destination_number(4000) =~ /^vmain$|^\*4000$|^\*98$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->xfer_vm] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [xfer_vm] destination_number(4000) =~ /^xfer_vm$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->is_transfer] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [is_transfer] destination_number(4000) =~ /^is_transfer$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->vmain_user] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [vmain_user] destination_number(4000) =~ /^\*97$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->allphones] continue=
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [allphones] destination_number(4000) =~ /^4200$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->private] continue=
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [private] destination_number(4000) =~ /^\*7000$/ break=on-true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [private] destination_number(4000) =~ /^7000$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->cf] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [cf] destination_number(4000) =~ /^cf$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->delay_echo] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [delay_echo] destination_number(4000) =~ /^\*9195$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->echo] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [echo] destination_number(4000) =~ /^\*9196$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->is_zrtp_secure] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [is_zrtp_secure] ${zrtp_secure_media_confirmed}() =~ /^true$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 ANTI-Action eval(not_secure) 
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->milliwatt] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [milliwatt] destination_number(4000) =~ /^\*9197$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->is_secure] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [is_secure] ${sip_via_protocol}(udp) =~ /tls/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->tone_stream] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [tone_stream] destination_number(4000) =~ /^\*9198$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->hold_music] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [hold_music] destination_number(4000) =~ /^\*9664$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->recordings] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [recordings] destination_number(4000) =~ /^\*(732)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->directory] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [directory] destination_number(4000) =~ /^\*411$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->wake-up] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [wake-up] destination_number(4000) =~ /^\*(925)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->Custom_valet_park_in] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [Custom_valet_park_in] destination_number(4000) =~ /^(park\+)?(\*5900)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->Custom_valet_park_out] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [Custom_valet_park_out] destination_number(4000) =~ /^(park\+)?\*(59[0-9][0-9])$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->operator] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [operator] destination_number(4000) =~ /^0$|^operator$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->operator-forward] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [operator-forward] destination_number(4000) =~ /^\*000$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->do-not-disturb] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [do-not-disturb] destination_number(4000) =~ /^\*77$/ break=on-true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [do-not-disturb] destination_number(4000) =~ /^\*78$|\*363$/ break=on-true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [do-not-disturb] destination_number(4000) =~ /^\*79$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->call-forward] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [call-forward] destination_number(4000) =~ /^\*72$/ break=on-true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [call-forward] destination_number(4000) =~ /^\*73$/ break=on-true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [call-forward] destination_number(4000) =~ /^\*74$/ break=on-true
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->call forward all] continue=
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [call forward all] ${user_exists}(false) =~ /^true/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->follow-me] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [follow-me] destination_number(4000) =~ /^\*21$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->clear_sip_auto_answer] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [clear_sip_auto_answer] ${click_to_call}() =~ /true/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->talking clock date and time] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [talking clock date and time] destination_number(4000) =~ /^\*9172$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->talking clock time] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [talking clock time] destination_number(4000) =~ /^\*9170$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->talking clock date] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [talking clock date] destination_number(4000) =~ /^\*9171$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->call_screen] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [call_screen] ${call_screen_enabled}() =~ /^true$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->local_extension] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [local_extension] ${user_exists}(false) =~ /true/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->voicemail] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [voicemail] ${user_exists}(false) =~ /true/ break=on-false
2018-08-29 13:24:48.395924 [DEBUG] switch_core_state_machine.c:286 (sofia/external/5195752944@208.89.129.46) State Change CS_ROUTING -> CS_EXECUTE
2018-08-29 13:24:48.395924 [DEBUG] switch_core_state_machine.c:643 (sofia/external/5195752944@208.89.129.46) State ROUTING going to sleep
2018-08-29 13:24:48.395924 [DEBUG] switch_core_state_machine.c:584 (sofia/external/5195752944@208.89.129.46) Running State Change CS_EXECUTE (Cur 1 Tot 46967)
2018-08-29 13:24:48.395924 [DEBUG] switch_core_state_machine.c:650 (sofia/external/5195752944@208.89.129.46) State EXECUTE
2018-08-29 13:24:48.395924 [DEBUG] mod_sofia.c:198 sofia/external/5195752944@208.89.129.46 SOFIA EXECUTE
2018-08-29 13:24:48.395924 [DEBUG] switch_core_state_machine.c:328 sofia/external/5195752944@208.89.129.46 Standard EXECUTE
EXECUTE sofia/external/5195752944@208.89.129.46 export(origination_callee_id_name=4000)
2018-08-29 13:24:48.395924 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [origination_callee_id_name]=[4000]
EXECUTE sofia/external/5195752944@208.89.129.46 set(RFC2822_DATE=Wed, 29 Aug 2018 13:24:48 -0400)
2018-08-29 13:24:48.395924 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [RFC2822_DATE]=[Wed, 29 Aug 2018 13:24:48 -0400]
EXECUTE sofia/external/5195752944@208.89.129.46 lua(app.lua call_block)
2018-08-29 13:24:48.395924 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('call_block', '')
2018-08-29 13:24:48.395924 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f67a409d500 Connected.
2018-08-29 13:24:48.415926 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f67a409d500 released.
2018-08-29 13:24:48.415926 [DEBUG] switch_cpp.cpp:1112 sofia/external/5195752944@208.89.129.46 destroy/unlink session from object
EXECUTE sofia/external/5195752944@208.89.129.46 hash(insert/thecarmel.uphone.ca-last_dial/5195752944/4000)
EXECUTE sofia/external/5195752944@208.89.129.46 transfer(4200 XML thecarmel.uphone.ca)
2018-08-29 13:24:48.415926 [DEBUG] switch_ivr.c:2165 (sofia/external/5195752944@208.89.129.46) State Change CS_EXECUTE -> CS_ROUTING
2018-08-29 13:24:48.415926 [NOTICE] switch_ivr.c:2172 Transfer sofia/external/5195752944@208.89.129.46 to XML[4200@thecarmel.uphone.ca]
2018-08-29 13:24:48.415926 [DEBUG] switch_core_state_machine.c:650 (sofia/external/5195752944@208.89.129.46) State EXECUTE going to sleep
2018-08-29 13:24:48.415926 [DEBUG] switch_core_state_machine.c:584 (sofia/external/5195752944@208.89.129.46) Running State Change CS_ROUTING (Cur 1 Tot 46967)
2018-08-29 13:24:48.415926 [DEBUG] switch_core_state_machine.c:643 (sofia/external/5195752944@208.89.129.46) State ROUTING
2018-08-29 13:24:48.415926 [DEBUG] mod_sofia.c:143 sofia/external/5195752944@208.89.129.46 SOFIA ROUTING
2018-08-29 13:24:48.415926 [DEBUG] switch_core_state_machine.c:236 sofia/external/5195752944@208.89.129.46 Standard ROUTING
2018-08-29 13:24:48.415926 [INFO] mod_dialplan_xml.c:637 Processing 5195752944 <5195752944>->4200 in context thecarmel.uphone.ca
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->user_exists] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [user_exists] () =~ // break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
2018-08-29 13:24:48.415926 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f67a409d500 Connected.
2018-08-29 13:24:48.415926 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f67a409d500 released.
EXECUTE sofia/external/5195752944@208.89.129.46 set(user_exists=false)
2018-08-29 13:24:48.415926 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [user_exists]=[false]
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->call-direction] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [call-direction] ${call_direction}(inbound) =~ /^(inbound|outbound|local)$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->variables] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [variables] () =~ // break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Action export(origination_callee_id_name=${destination_number}) 
Dialplan: sofia/external/5195752944@208.89.129.46 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) 
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->call_block] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [call_block] ${call_blocked}() =~ /^true$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 ANTI-Action lua(app.lua call_block) 
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->user_record] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [user_record] () =~ // break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Action set(user_record=${user_data ${destination_number}@${domain_name} var user_record}) INLINE
2018-08-29 13:24:48.435922 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f67a409d500 Connected.
2018-08-29 13:24:48.435922 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f67a409d500 released.
2018-08-29 13:24:48.435922 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f67a409d500 Connected.
2018-08-29 13:24:48.435922 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f67a409d500 released.
EXECUTE sofia/external/5195752944@208.89.129.46 set(user_record=)
2018-08-29 13:24:48.435922 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [user_record]=[UNDEF]
Dialplan: sofia/external/5195752944@208.89.129.46 Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
2018-08-29 13:24:48.435922 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f67a409d500 Connected.
2018-08-29 13:24:48.435922 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f67a409d500 released.
EXECUTE sofia/external/5195752944@208.89.129.46 set(from_user_exists=false)
2018-08-29 13:24:48.435922 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [from_user_exists]=[false]
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [user_record] ${call_direction}(inbound) =~ /^inbound$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^outbound$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^local$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [user_record] ${call_direction}(inbound) =~ /^inbound$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^outbound$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^local$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->redial] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [redial] destination_number(4200) =~ /^(redial|\*870)$/ break=on-true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [redial] () =~ // break=never
Dialplan: sofia/external/5195752944@208.89.129.46 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) 
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->speed_dial] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [speed_dial] destination_number(4200) =~ /^\*0(.*)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->911-Iris] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [911-Iris] destination_number(4200) =~ /^911$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->911-Iris-copy] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [911-Iris-copy] destination_number(4200) =~ /^911$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->922-test] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [922-test] destination_number(4200) =~ /^922$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->country_variables] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [country_variables] () =~ // break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Action set(toll_allow=all) INLINE
EXECUTE sofia/external/5195752944@208.89.129.46 set(toll_allow=all)
2018-08-29 13:24:48.455922 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [toll_allow]=[all]
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->outbound_call_restriction] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [outbound_call_restriction] ${call_direction}(inbound) =~ /^(outbound)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->local_dids] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [local_dids] destination_number(4200) =~ /^\+?1?(\d{10})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->CanadaCalling] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [CanadaCalling] ${toll_allow}(all) =~ /all|canada|northamerica/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [CanadaCalling] destination_number(4200) =~ /^\+?1?((204|226|236|249|250|289|306|343|343|365|403|416|418|431|437|438|450|506|514|519|548|579|581|587|604|613|613|639|647|705|709|778|780|782|782|807|819|825|867|867|867|873|902|902|905)[2-9]\d{6})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->US_Calling] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [US_Calling] ${toll_allow}(all) =~ /all|northamerica|unitedstates/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [US_Calling] destination_number(4200) =~ /^\+?1?((201|202|203|205|206|207|208|209|210|212|213|214|215|216|217|218|219|220|224|225|227|228|229|231|234|239|240|248|251|252|253|254|256|260|262|267|269|270|272|274|276|281|283|301|302|303|304|305|307|308|309|310|312|313|314|315|316|317|318|319|320|321|323|325|327|330|331|332|334|336|337|339|346|347|351|352|360|361|364|380|385|386|401|402|404|405|406|407|408|409|410|412|413|414|415|417|419|423|424|425|430|432|434|435|440|442|443|447|458|463|464|469|470|475|478|479|480|484|501|502|503|504|505|507|508|509|510|512|513|515|516|517|518|520|530|531|534|539|540|541|551|557|559|561|562|563|564|567|570|571|573|574|575|580|585|586|601|602|603|605|606|607|608|609|610|612|614|615|616|617|618|619|620|623|626|628|629|630|631|636|641|646|650|651|657|659|660|661|662|667|669|678|679|680|681|682|689|701|702|703|704|706|707|708|712|713|714|715|716|717|718|719|720|724|725|726|727|730|731|732|734|737|740|743|747|754|757|760|762|763|765|769|770|772|773|774|775|779|781|785|786|801|802|803|804|805|806|808|810|812|813|814|815|816|817|818|828|830|831|832|838|843|845|847|848|850|854|856|857|858|859|860|862|863|864|865|870|872|878|901|903|904|906|907|908|909|910|912|913|914|915|916|917|918|919|920|925|928|929|930|931|934|936|937|938|940|941|947|949|951|952|954|956|959|970|971|972|973|975|978|979|980|984|985|986|989)[2-9]\d{6})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->Toll-Free_Calling] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [Toll-Free_Calling] destination_number(4200) =~ /^\+?1?(8(00|33|44|55|66|77|88)[2-9]\d{6})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->310-Iris] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [310-Iris] destination_number(4200) =~ /^310(\d{4})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->Anguilla] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [Anguilla] destination_number(4200) =~ /^\+?1?(264[2-9]\d{6})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->Bermuda] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [Bermuda] ${toll_allow}(all) =~ /all|northamerica|bermuda/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [Bermuda] destination_number(4200) =~ /^\+?1?(441[2-9]\d{6})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->Jamaica] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [Jamaica] destination_number(4200) =~ /^\+?1?(876[2-9]\d{6})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->agent_status] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [agent_status] destination_number(4200) =~ /^\*22$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->International-LCR] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [International-LCR] ${toll_allow}(all) =~ /all|international|CAUSInternational/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [International-LCR] destination_number(4200) =~ /^(011|00)(\d{9,17})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->sbc.voxbeam.com.International-copy] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [sbc.voxbeam.com.International-copy] destination_number(4200) =~ /^(011|00)(\d{9,17})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->agent_status_id] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [agent_status_id] destination_number(4200) =~ /^\*23$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->group-intercept] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [group-intercept] destination_number(4200) =~ /^\*8$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->page-extension] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [page-extension] destination_number(4200) =~ /^\*8(\d{2,7})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->eavesdrop] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [eavesdrop] destination_number(4200) =~ /^\*33(\d{2,7})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->call_privacy] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [call_privacy] destination_number(4200) =~ /^\*67(\d+)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->call_return] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [call_return] destination_number(4200) =~ /^\*69$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->extension_queue] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [extension_queue] destination_number(4200) =~ /^\*800(.*)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->intercept-ext] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [intercept-ext] destination_number(4200) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->intercept-ext-polycom] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [intercept-ext-polycom] destination_number(4200) =~ /^\*97(\d+)$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->dx] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [dx] destination_number(4200) =~ /^dx$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->no-ring] continue=true
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [no-ring] destination_number(4200) =~ /^4000$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->att_xfer] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [att_xfer] destination_number(4200) =~ /^att_xfer$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->Carmel-Fax] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [Carmel-Fax] destination_number(4200) =~ /^125$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->extension-to-voicemail] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [extension-to-voicemail] ${user_exists}(false) =~ /^true$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->send_to_voicemail] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [send_to_voicemail] destination_number(4200) =~ /^\*99(\d{2,10})$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->vmain] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [vmain] destination_number(4200) =~ /^vmain$|^\*4000$|^\*98$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->xfer_vm] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [xfer_vm] destination_number(4200) =~ /^xfer_vm$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->is_transfer] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [is_transfer] destination_number(4200) =~ /^is_transfer$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->vmain_user] continue=false
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (FAIL) [vmain_user] destination_number(4200) =~ /^\*97$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 parsing [thecarmel.uphone.ca->allphones] continue=
Dialplan: sofia/external/5195752944@208.89.129.46 Regex (PASS) [allphones] destination_number(4200) =~ /^4200$/ break=on-false
Dialplan: sofia/external/5195752944@208.89.129.46 Action set(ring_group_uuid=fcb49e4a-3852-4652-b708-837db39d3afe) 
Dialplan: sofia/external/5195752944@208.89.129.46 Action lua(app.lua ring_groups) 
2018-08-29 13:24:48.455922 [DEBUG] switch_core_state_machine.c:286 (sofia/external/5195752944@208.89.129.46) State Change CS_ROUTING -> CS_EXECUTE
2018-08-29 13:24:48.455922 [DEBUG] switch_core_state_machine.c:643 (sofia/external/5195752944@208.89.129.46) State ROUTING going to sleep
2018-08-29 13:24:48.455922 [DEBUG] switch_core_state_machine.c:584 (sofia/external/5195752944@208.89.129.46) Running State Change CS_EXECUTE (Cur 1 Tot 46967)
2018-08-29 13:24:48.455922 [DEBUG] switch_core_state_machine.c:650 (sofia/external/5195752944@208.89.129.46) State EXECUTE
2018-08-29 13:24:48.455922 [DEBUG] mod_sofia.c:198 sofia/external/5195752944@208.89.129.46 SOFIA EXECUTE
2018-08-29 13:24:48.455922 [DEBUG] switch_core_state_machine.c:328 sofia/external/5195752944@208.89.129.46 Standard EXECUTE
EXECUTE sofia/external/5195752944@208.89.129.46 export(origination_callee_id_name=4200)
2018-08-29 13:24:48.455922 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [origination_callee_id_name]=[4200]
EXECUTE sofia/external/5195752944@208.89.129.46 set(RFC2822_DATE=Wed, 29 Aug 2018 13:24:48 -0400)
2018-08-29 13:24:48.455922 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [RFC2822_DATE]=[Wed, 29 Aug 2018 13:24:48 -0400]
EXECUTE sofia/external/5195752944@208.89.129.46 lua(app.lua call_block)
2018-08-29 13:24:48.455922 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('call_block', '')
2018-08-29 13:24:48.455922 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f67a409d500 Connected.
2018-08-29 13:24:48.455922 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f67a409d500 released.
2018-08-29 13:24:48.455922 [DEBUG] switch_cpp.cpp:1112 sofia/external/5195752944@208.89.129.46 destroy/unlink session from object
EXECUTE sofia/external/5195752944@208.89.129.46 hash(insert/thecarmel.uphone.ca-last_dial/5195752944/4200)
EXECUTE sofia/external/5195752944@208.89.129.46 set(ring_group_uuid=fcb49e4a-3852-4652-b708-837db39d3afe)
2018-08-29 13:24:48.455922 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [ring_group_uuid]=[fcb49e4a-3852-4652-b708-837db39d3afe]
EXECUTE sofia/external/5195752944@208.89.129.46 lua(app.lua ring_groups)
2018-08-29 13:24:48.455922 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f67a409d500 Connected.
2018-08-29 13:24:48.575936 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('ringback', 'tone_stream://%(2000, 4000, 440.0, 480.0);loops=-1')
2018-08-29 13:24:48.575936 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('transfer_ringback', 'tone_stream://%(2000, 4000, 440.0, 480.0);loops=-1')
EXECUTE sofia/external/5195752944@208.89.129.46 set(uuids=75894385-872f-4621-aa15-71d46af45bcc)
2018-08-29 13:24:48.575936 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [uuids]=[75894385-872f-4621-aa15-71d46af45bcc]
EXECUTE sofia/external/5195752944@208.89.129.46 export(sip_h_Alert-Info=)
2018-08-29 13:24:48.575936 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [sip_h_Alert-Info]=[UNDEF]
EXECUTE sofia/external/5195752944@208.89.129.46 set(group_confirm_key=exec)
2018-08-29 13:24:48.575936 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [group_confirm_key]=[exec]
EXECUTE sofia/external/5195752944@208.89.129.46 set(group_confirm_file=lua /usr/share/freeswitch/scripts/confirm.lua)
2018-08-29 13:24:48.575936 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [group_confirm_file]=[lua /usr/share/freeswitch/scripts/confirm.lua]
2018-08-29 13:24:48.575936 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('ringback', 'tone_stream://%(2000, 4000, 440.0, 480.0);loops=-1')
2018-08-29 13:24:48.575936 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('transfer_ringback', 'tone_stream://%(2000, 4000, 440.0, 480.0);loops=-1')
EXECUTE sofia/external/5195752944@208.89.129.46 set(uuids=75894385-872f-4621-aa15-71d46af45bcc,5a09592f-9ad7-4f24-9e8c-9a285cd6183d)
2018-08-29 13:24:48.575936 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [uuids]=[75894385-872f-4621-aa15-71d46af45bcc,5a09592f-9ad7-4f24-9e8c-9a285cd6183d]
EXECUTE sofia/external/5195752944@208.89.129.46 export(sip_h_Alert-Info=)
2018-08-29 13:24:48.575936 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [sip_h_Alert-Info]=[UNDEF]
EXECUTE sofia/external/5195752944@208.89.129.46 set(group_confirm_key=exec)
2018-08-29 13:24:48.575936 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [group_confirm_key]=[exec]
EXECUTE sofia/external/5195752944@208.89.129.46 set(group_confirm_file=lua /usr/share/freeswitch/scripts/confirm.lua)
2018-08-29 13:24:48.575936 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [group_confirm_file]=[lua /usr/share/freeswitch/scripts/confirm.lua]
2018-08-29 13:24:48.595933 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('ringback', 'tone_stream://%(2000, 4000, 440.0, 480.0);loops=-1')
2018-08-29 13:24:48.595933 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('transfer_ringback', 'tone_stream://%(2000, 4000, 440.0, 480.0);loops=-1')
EXECUTE sofia/external/5195752944@208.89.129.46 set(uuids=75894385-872f-4621-aa15-71d46af45bcc,5a09592f-9ad7-4f24-9e8c-9a285cd6183d,522e73b7-dc56-4c15-98ce-eee6a3382400)
2018-08-29 13:24:48.595933 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [uuids]=[75894385-872f-4621-aa15-71d46af45bcc,5a09592f-9ad7-4f24-9e8c-9a285cd6183d,522e73b7-dc56-4c15-98ce-eee6a3382400]
EXECUTE sofia/external/5195752944@208.89.129.46 export(sip_h_Alert-Info=)
2018-08-29 13:24:48.595933 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [sip_h_Alert-Info]=[UNDEF]
EXECUTE sofia/external/5195752944@208.89.129.46 set(group_confirm_key=exec)
2018-08-29 13:24:48.595933 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [group_confirm_key]=[exec]
EXECUTE sofia/external/5195752944@208.89.129.46 set(group_confirm_file=lua /usr/share/freeswitch/scripts/confirm.lua)
2018-08-29 13:24:48.595933 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [group_confirm_file]=[lua /usr/share/freeswitch/scripts/confirm.lua]
2018-08-29 13:24:48.595933 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('ringback', 'tone_stream://%(2000, 4000, 440.0, 480.0);loops=-1')
2018-08-29 13:24:48.595933 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('transfer_ringback', 'tone_stream://%(2000, 4000, 440.0, 480.0);loops=-1')
EXECUTE sofia/external/5195752944@208.89.129.46 set(uuids=75894385-872f-4621-aa15-71d46af45bcc,5a09592f-9ad7-4f24-9e8c-9a285cd6183d,522e73b7-dc56-4c15-98ce-eee6a3382400,0a4956f7-c7de-458a-b19e-e614e0368c08)
2018-08-29 13:24:48.595933 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [uuids]=[75894385-872f-4621-aa15-71d46af45bcc,5a09592f-9ad7-4f24-9e8c-9a285cd6183d,522e73b7-dc56-4c15-98ce-eee6a3382400,0a4956f7-c7de-458a-b19e-e614e0368c08]
EXECUTE sofia/external/5195752944@208.89.129.46 export(sip_h_Alert-Info=)
2018-08-29 13:24:48.595933 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [sip_h_Alert-Info]=[UNDEF]
EXECUTE sofia/external/5195752944@208.89.129.46 set(group_confirm_key=exec)
2018-08-29 13:24:48.595933 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [group_confirm_key]=[exec]
EXECUTE sofia/external/5195752944@208.89.129.46 set(group_confirm_file=lua /usr/share/freeswitch/scripts/confirm.lua)
2018-08-29 13:24:48.595933 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [group_confirm_file]=[lua /usr/share/freeswitch/scripts/confirm.lua]
2018-08-29 13:24:48.595933 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('ringback', 'tone_stream://%(2000, 4000, 440.0, 480.0);loops=-1')
2018-08-29 13:24:48.595933 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('transfer_ringback', 'tone_stream://%(2000, 4000, 440.0, 480.0);loops=-1')
EXECUTE sofia/external/5195752944@208.89.129.46 set(uuids=75894385-872f-4621-aa15-71d46af45bcc,5a09592f-9ad7-4f24-9e8c-9a285cd6183d,522e73b7-dc56-4c15-98ce-eee6a3382400,0a4956f7-c7de-458a-b19e-e614e0368c08,0bae4e82-bebd-4fe2-b783-6368158e7de5)
2018-08-29 13:24:48.595933 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [uuids]=[75894385-872f-4621-aa15-71d46af45bcc,5a09592f-9ad7-4f24-9e8c-9a285cd6183d,522e73b7-dc56-4c15-98ce-eee6a3382400,0a4956f7-c7de-458a-b19e-e614e0368c08,0bae4e82-bebd-4fe2-b783-6368158e7de5]
EXECUTE sofia/external/5195752944@208.89.129.46 export(sip_h_Alert-Info=)
2018-08-29 13:24:48.595933 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [sip_h_Alert-Info]=[UNDEF]
EXECUTE sofia/external/5195752944@208.89.129.46 set(group_confirm_key=exec)
2018-08-29 13:24:48.595933 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [group_confirm_key]=[exec]
EXECUTE sofia/external/5195752944@208.89.129.46 set(group_confirm_file=lua /usr/share/freeswitch/scripts/confirm.lua)
2018-08-29 13:24:48.615928 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [group_confirm_file]=[lua /usr/share/freeswitch/scripts/confirm.lua]
2018-08-29 13:24:48.615928 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('ringback', 'tone_stream://%(2000, 4000, 440.0, 480.0);loops=-1')
2018-08-29 13:24:48.615928 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('transfer_ringback', 'tone_stream://%(2000, 4000, 440.0, 480.0);loops=-1')
EXECUTE sofia/external/5195752944@208.89.129.46 set(uuids=75894385-872f-4621-aa15-71d46af45bcc,5a09592f-9ad7-4f24-9e8c-9a285cd6183d,522e73b7-dc56-4c15-98ce-eee6a3382400,0a4956f7-c7de-458a-b19e-e614e0368c08,0bae4e82-bebd-4fe2-b783-6368158e7de5,a9b26888-a3ac-40f6-b571-0d6cb07801df)
2018-08-29 13:24:48.615928 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [uuids]=[75894385-872f-4621-aa15-71d46af45bcc,5a09592f-9ad7-4f24-9e8c-9a285cd6183d,522e73b7-dc56-4c15-98ce-eee6a3382400,0a4956f7-c7de-458a-b19e-e614e0368c08,0bae4e82-bebd-4fe2-b783-6368158e7de5,a9b26888-a3ac-40f6-b571-0d6cb07801df]
EXECUTE sofia/external/5195752944@208.89.129.46 export(sip_h_Alert-Info=)
2018-08-29 13:24:48.615928 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [sip_h_Alert-Info]=[UNDEF]
EXECUTE sofia/external/5195752944@208.89.129.46 set(group_confirm_key=exec)
2018-08-29 13:24:48.615928 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [group_confirm_key]=[exec]
EXECUTE sofia/external/5195752944@208.89.129.46 set(group_confirm_file=lua /usr/share/freeswitch/scripts/confirm.lua)
2018-08-29 13:24:48.615928 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [group_confirm_file]=[lua /usr/share/freeswitch/scripts/confirm.lua]
2018-08-29 13:24:48.615928 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('ringback', 'tone_stream://%(2000, 4000, 440.0, 480.0);loops=-1')
2018-08-29 13:24:48.615928 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('transfer_ringback', 'tone_stream://%(2000, 4000, 440.0, 480.0);loops=-1')
EXECUTE sofia/external/5195752944@208.89.129.46 set(uuids=75894385-872f-4621-aa15-71d46af45bcc,5a09592f-9ad7-4f24-9e8c-9a285cd6183d,522e73b7-dc56-4c15-98ce-eee6a3382400,0a4956f7-c7de-458a-b19e-e614e0368c08,0bae4e82-bebd-4fe2-b783-6368158e7de5,a9b26888-a3ac-40f6-b571-0d6cb07801df,8ff411a9-882b-40ed-a1bf-d4c67b8a709b)
2018-08-29 13:24:48.615928 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [uuids]=[75894385-872f-4621-aa15-71d46af45bcc,5a09592f-9ad7-4f24-9e8c-9a285cd6183d,522e73b7-dc56-4c15-98ce-eee6a3382400,0a4956f7-c7de-458a-b19e-e614e0368c08,0bae4e82-bebd-4fe2-b783-6368158e7de5,a9b26888-a3ac-40f6-b571-0d6cb07801df,8ff411a9-882b-40ed-a1bf-d4c67b8a709b]
EXECUTE sofia/external/5195752944@208.89.129.46 export(sip_h_Alert-Info=)
2018-08-29 13:24:48.615928 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [sip_h_Alert-Info]=[UNDEF]
EXECUTE sofia/external/5195752944@208.89.129.46 set(group_confirm_key=exec)
2018-08-29 13:24:48.615928 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [group_confirm_key]=[exec]
EXECUTE sofia/external/5195752944@208.89.129.46 set(group_confirm_file=lua /usr/share/freeswitch/scripts/confirm.lua)
2018-08-29 13:24:48.615928 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [group_confirm_file]=[lua /usr/share/freeswitch/scripts/confirm.lua]
EXECUTE sofia/external/5195752944@208.89.129.46 set(hangup_after_bridge=true)
2018-08-29 13:24:48.635932 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [hangup_after_bridge]=[true]
EXECUTE sofia/external/5195752944@208.89.129.46 set(continue_on_fail=true)
2018-08-29 13:24:48.635932 [DEBUG] mod_dptools.c:1530 SET sofia/external/5195752944@208.89.129.46 [continue_on_fail]=[true]
EXECUTE sofia/external/5195752944@208.89.129.46 bind_digit_action(local,*1,exec:execute_extension,dx XML thecarmel.uphone.ca,peer)
2018-08-29 13:24:48.635932 [INFO] switch_ivr_async.c:214 Digit parser DPTOOLS: Setting realm to 'local'
2018-08-29 13:24:48.635932 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *1/local/0 callback: 0x7f678bb89956 data: 0x7f67900b5068
EXECUTE sofia/external/5195752944@208.89.129.46 bind_digit_action(local,*2,exec:record_session,/var/lib/freeswitch/recordings/thecarmel.uphone.ca/archive/2018/Aug/29/be373d2a-b115-4ab2-8037-5a7b62a392cc.wav,peer)
2018-08-29 13:24:48.635932 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *2/local/0 callback: 0x7f678bb89956 data: 0x7f67900b5248
EXECUTE sofia/external/5195752944@208.89.129.46 bind_digit_action(local,*3,exec:execute_extension,cf XML thecarmel.uphone.ca,peer)
2018-08-29 13:24:48.635932 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *3/local/0 callback: 0x7f678bb89956 data: 0x7f67900b53c8
EXECUTE sofia/external/5195752944@208.89.129.46 bind_digit_action(local,*4,exec:execute_extension,att_xfer XML thecarmel.uphone.ca,peer)
2018-08-29 13:24:48.635932 [DEBUG] switch_ivr_async.c:323 Digit parser DPTOOLS: binding *4/local/0 callback: 0x7f678bb89956 data: 0x7f67900b5508
EXECUTE sofia/external/5195752944@208.89.129.46 digit_action_set_realm(local)
2018-08-29 13:24:48.635932 [NOTICE] switch_cpp.cpp:1365 [ring group] app_data: {ignore_early_media=true}[sip_invite_domain=thecarmel.uphone.ca,call_direction=inbound,confirm=false,leg_timeout=25,leg_delay_start=0,dialed_extension=100,extension_uuid=d0148c31-6763-47c7-8794-c57347a00265]user/100@thecarmel.uphone.ca,[sip_invite_domain=thecarmel.uphone.ca,call_direction=inbound,confirm=false,leg_timeout=25,leg_delay_start=0,dialed_extension=101,extension_uuid=e2e517a9-2741-4661-8436-2d1ac9db76e2]user/101@thecarmel.uphone.ca,[sip_invite_domain=thecarmel.uphone.ca,call_direction=inbound,confirm=false,leg_timeout=25,leg_delay_start=0,dialed_extension=105,extension_uuid=2c97355e-9afc-45c9-a550-ebd5a5dfcc23]user/105@thecarmel.uphone.ca,[sip_invite_domain=thecarmel.uphone.ca,call_direction=inbound,confirm=false,leg_timeout=25,leg_delay_start=0,dialed_extension=106,extension_uuid=ead3420b-9f5a-4fdd-a865-b841306691d5]user/106@thecarmel.uphone.ca,[sip_invite_domain=thecarmel.uphone.ca,call_direction=inbound,confirm=false,leg_timeout=25,leg_delay_start=0,dialed_extension=107,extension_uuid=21b0a948-6f17-40a5-ba85-dd5760636887]user/107@thecarmel.uphone.ca,[sip_invite_domain=thecarmel.uphone.ca,call_direction=inbound,confirm=false,leg_timeout=25,leg_delay_start=0,dialed_extension=108,extension_uuid=aa0e1824-d818-46ef-8009-0f1eddf8e349]user/108@thecarmel.uphone.ca,[sip_invite_domain=thecarmel.uphone.ca,call_direction=inbound,confirm=false,leg_timeout=25,leg_delay_start=0,dialed_extension=109,extension_uuid=94740196-e7c6-4695-b589-8b995e0b51fe]user/109@thecarmel.uphone.ca
EXECUTE sofia/external/5195752944@208.89.129.46 bridge({ignore_early_media=true}[sip_invite_domain=thecarmel.uphone.ca,call_direction=inbound,confirm=false,leg_timeout=25,leg_delay_start=0,dialed_extension=100,extension_uuid=d0148c31-6763-47c7-8794-c57347a00265]user/100@thecarmel.uphone.ca,[sip_invite_domain=thecarmel.uphone.ca,call_direction=inbound,confirm=false,leg_timeout=25,leg_delay_start=0,dialed_extension=101,extension_uuid=e2e517a9-2741-4661-8436-2d1ac9db76e2]user/101@thecarmel.uphone.ca,[sip_invite_domain=thecarmel.uphone.ca,call_direction=inbound,confirm=false,leg_timeout=25,leg_delay_start=0,dialed_extension=105,extension_uuid=2c97355e-9afc-45c9-a550-ebd5a5dfcc23]user/105@thecarmel.uphone.ca,[sip_invite_domain=thecarmel.uphone.ca,call_direction=inbound,confirm=false,leg_timeout=25,leg_delay_start=0,dialed_extension=106,extension_uuid=ead3420b-9f5a-4fdd-a865-b841306691d5]user/106@thecarmel.uphone.ca,[sip_invite_domain=thecarmel.uphone.ca,call_direction=inbound,confirm=false,leg_timeout=25,leg_delay_start=0,dialed_extension=107,extension_uuid=21b0a948-6f17-40a5-ba85-dd5760636887]user/107@thecarmel.uphone.ca,[sip_invite_domain=thecarmel.uphone.ca,call_direction=inbound,confirm=false,leg_timeout=25,leg_delay_start=0,dialed_extension=108,extension_uuid=aa0e1824-d818-46ef-8009-0f1eddf8e349]user/108@thecarmel.uphone.ca,[sip_invite_domain=thecarmel.uphone.ca,call_direction=inbound,confirm=false,leg_timeout=25,leg_delay_start=0,dialed_extension=109,extension_uuid=94740196-e7c6-4695-b589-8b995e0b51fe]user/109@thecarmel.uphone.ca)
2018-08-29 13:24:48.635932 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [effective_caller_id_name]=[Adrien Alexson] to event
2018-08-29 13:24:48.635932 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [caller_id_name]=[Adrien Alexson] to event
2018-08-29 13:24:48.635932 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [origination_callee_id_name]=[4200] to event
2018-08-29 13:24:48.635932 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [origination_callee_id_name]=[4200] to event
2018-08-29 13:24:48.635932 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [origination_callee_id_name]=[4200] to event
2018-08-29 13:24:48.635932 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2018-08-29 13:24:48.635932 [DEBUG] switch_ivr_originate.c:2663 Parsing session specific variables
2018-08-29 13:24:48.635932 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f67a409d500 Connected.
2018-08-29 13:24:48.635932 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f679012a2c0 Connected.
2018-08-29 13:24:48.635932 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f679012a2c0 released.
2018-08-29 13:24:48.655930 [NOTICE] switch_cpp.cpp:1365 [xml_handler] local_hostname: voip-ss-001.uphone.ca database_hostname: voip-ss-002.uphone.ca dial_string: {sip_h_X-context=thecarmel.uphone.ca,sip_invite_domain=thecarmel.uphone.ca,presence_id=100@thecarmel.uphone.ca}sofia/internal/100@thecarmel.uphone.ca;fs_path=sip:voip-ss-002.uphone.ca
2018-08-29 13:24:48.655930 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f67a409d500 released.
2018-08-29 13:24:48.655930 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [effective_caller_id_name]=[Adrien Alexson] to event
2018-08-29 13:24:48.655930 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [caller_id_name]=[Adrien Alexson] to event
2018-08-29 13:24:48.655930 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [origination_callee_id_name]=[4200] to event
2018-08-29 13:24:48.655930 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [origination_callee_id_name]=[4200] to event
2018-08-29 13:24:48.655930 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [origination_callee_id_name]=[4200] to event
2018-08-29 13:24:48.655930 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2018-08-29 13:24:48.655930 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/100@thecarmel.uphone.ca [8a155f8b-bd48-443e-9783-74781ff86da0]
2018-08-29 13:24:48.655930 [DEBUG] mod_sofia.c:4818 (sofia/internal/100@thecarmel.uphone.ca) State Change CS_NEW -> CS_INIT
2018-08-29 13:24:48.655930 [DEBUG] switch_ivr_originate.c:2957 sofia/internal/100@thecarmel.uphone.ca Setting leg timeout to 25
2018-08-29 13:24:48.655930 [DEBUG] switch_ivr_originate.c:2957 sofia/internal/100@thecarmel.uphone.ca Setting leg timeout to 25
2018-08-29 13:24:48.655930 [DEBUG] switch_ivr_originate.c:2663 Parsing session specific variables
2018-08-29 13:24:48.655930 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/100@thecarmel.uphone.ca) Running State Change CS_INIT (Cur 2 Tot 46968)
2018-08-29 13:24:48.655930 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/100@thecarmel.uphone.ca) State INIT
2018-08-29 13:24:48.655930 [DEBUG] mod_sofia.c:90 sofia/internal/100@thecarmel.uphone.ca SOFIA INIT
2018-08-29 13:24:48.655930 [DEBUG] sofia_glue.c:1264 sip:voip-ss-002.uphone.ca Setting proxy route to sofia/internal/100@thecarmel.uphone.ca
2018-08-29 13:24:48.655930 [DEBUG] sofia_glue.c:1295 sofia/internal/100@thecarmel.uphone.ca sending invite version: 1.6.16  64bit
Local SDP:
v=0
o=FreeSWITCH 1535533444 1535533445 IN IP4 208.90.97.6
s=FreeSWITCH
c=IN IP4 208.90.97.6
t=0 0
m=audio 30044 RTP/AVP 0 8 18 3 102 101 13 103 104
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:3 GSM/8000
a=rtpmap:102 opus/48000/2
a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:103 telephone-event/48000
a=fmtp:103 0-16
a=rtcp-mux
a=rtcp:30044 IN IP4 208.90.97.6
a=rtpmap:13 CN/8000
a=rtpmap:104 CN/48000
a=ptime:20
a=sendrecv

2018-08-29 13:24:48.655930 [DEBUG] switch_core_state_machine.c:40 sofia/internal/100@thecarmel.uphone.ca Standard INIT
2018-08-29 13:24:48.655930 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/100@thecarmel.uphone.ca) State Change CS_INIT -> CS_ROUTING
2018-08-29 13:24:48.655930 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/100@thecarmel.uphone.ca) State INIT going to sleep
2018-08-29 13:24:48.655930 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/100@thecarmel.uphone.ca) Running State Change CS_ROUTING (Cur 2 Tot 46968)
2018-08-29 13:24:48.655930 [DEBUG] sofia.c:7048 Channel sofia/internal/100@thecarmel.uphone.ca entering state [calling][0]
2018-08-29 13:24:48.655930 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/100@thecarmel.uphone.ca) State ROUTING
2018-08-29 13:24:48.655930 [DEBUG] mod_sofia.c:143 sofia/internal/100@thecarmel.uphone.ca SOFIA ROUTING
2018-08-29 13:24:48.655930 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/100@thecarmel.uphone.ca) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2018-08-29 13:24:48.655930 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/100@thecarmel.uphone.ca) State ROUTING going to sleep
2018-08-29 13:24:48.655930 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/100@thecarmel.uphone.ca) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 46968)
2018-08-29 13:24:48.655930 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/100@thecarmel.uphone.ca) State CONSUME_MEDIA
2018-08-29 13:24:48.655930 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/100@thecarmel.uphone.ca) State CONSUME_MEDIA going to sleep
2018-08-29 13:24:48.655930 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f67a409d500 Connected.
2018-08-29 13:24:48.655930 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f679012a2c0 Connected.
2018-08-29 13:24:48.655930 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f679012a2c0 released.
2018-08-29 13:24:48.675926 [NOTICE] switch_cpp.cpp:1365 [xml_handler] local_hostname: voip-ss-001.uphone.ca database_hostname: voip-ss-002.uphone.ca dial_string: {sip_h_X-context=thecarmel.uphone.ca,sip_invite_domain=thecarmel.uphone.ca,presence_id=101@thecarmel.uphone.ca}sofia/internal/101@thecarmel.uphone.ca;fs_path=sip:voip-ss-002.uphone.ca
2018-08-29 13:24:48.675926 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f67a409d500 released.
2018-08-29 13:24:48.675926 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [effective_caller_id_name]=[Adrien Alexson] to event
2018-08-29 13:24:48.675926 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [caller_id_name]=[Adrien Alexson] to event
2018-08-29 13:24:48.675926 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [origination_callee_id_name]=[4200] to event
2018-08-29 13:24:48.675926 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [origination_callee_id_name]=[4200] to event
2018-08-29 13:24:48.675926 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [origination_callee_id_name]=[4200] to event
2018-08-29 13:24:48.675926 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2018-08-29 13:24:48.675926 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/101@thecarmel.uphone.ca [7f659e37-b123-4f5d-9731-cd4e9c911107]
2018-08-29 13:24:48.675926 [DEBUG] mod_sofia.c:4818 (sofia/internal/101@thecarmel.uphone.ca) State Change CS_NEW -> CS_INIT
2018-08-29 13:24:48.675926 [DEBUG] switch_ivr_originate.c:2957 sofia/internal/101@thecarmel.uphone.ca Setting leg timeout to 25
2018-08-29 13:24:48.675926 [DEBUG] switch_ivr_originate.c:2957 sofia/internal/101@thecarmel.uphone.ca Setting leg timeout to 25
2018-08-29 13:24:48.675926 [DEBUG] switch_ivr_originate.c:2663 Parsing session specific variables
2018-08-29 13:24:48.675926 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/101@thecarmel.uphone.ca) Running State Change CS_INIT (Cur 3 Tot 46969)
2018-08-29 13:24:48.675926 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/101@thecarmel.uphone.ca) State INIT
2018-08-29 13:24:48.675926 [DEBUG] mod_sofia.c:90 sofia/internal/101@thecarmel.uphone.ca SOFIA INIT
2018-08-29 13:24:48.675926 [DEBUG] sofia_glue.c:1264 sip:voip-ss-002.uphone.ca Setting proxy route to sofia/internal/101@thecarmel.uphone.ca
2018-08-29 13:24:48.675926 [DEBUG] sofia_glue.c:1295 sofia/internal/101@thecarmel.uphone.ca sending invite version: 1.6.16  64bit
Local SDP:
v=0
o=FreeSWITCH 1535540964 1535540965 IN IP4 208.90.97.6
s=FreeSWITCH
c=IN IP4 208.90.97.6
t=0 0
m=audio 22524 RTP/AVP 0 8 18 3 102 101 13 103 104
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:3 GSM/8000
a=rtpmap:102 opus/48000/2
a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:103 telephone-event/48000
a=fmtp:103 0-16
a=rtcp-mux
a=rtcp:22524 IN IP4 208.90.97.6
a=rtpmap:13 CN/8000
a=rtpmap:104 CN/48000
a=ptime:20
a=sendrecv

2018-08-29 13:24:48.675926 [DEBUG] switch_core_state_machine.c:40 sofia/internal/101@thecarmel.uphone.ca Standard INIT
2018-08-29 13:24:48.675926 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/101@thecarmel.uphone.ca) State Change CS_INIT -> CS_ROUTING
2018-08-29 13:24:48.675926 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/101@thecarmel.uphone.ca) State INIT going to sleep
2018-08-29 13:24:48.675926 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/101@thecarmel.uphone.ca) Running State Change CS_ROUTING (Cur 3 Tot 46969)
2018-08-29 13:24:48.675926 [DEBUG] sofia.c:7048 Channel sofia/internal/101@thecarmel.uphone.ca entering state [calling][0]
2018-08-29 13:24:48.675926 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/101@thecarmel.uphone.ca) State ROUTING
2018-08-29 13:24:48.675926 [DEBUG] mod_sofia.c:143 sofia/internal/101@thecarmel.uphone.ca SOFIA ROUTING
2018-08-29 13:24:48.675926 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/101@thecarmel.uphone.ca) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2018-08-29 13:24:48.675926 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/101@thecarmel.uphone.ca) State ROUTING going to sleep
2018-08-29 13:24:48.675926 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/101@thecarmel.uphone.ca) Running State Change CS_CONSUME_MEDIA (Cur 3 Tot 46969)
2018-08-29 13:24:48.675926 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/101@thecarmel.uphone.ca) State CONSUME_MEDIA
2018-08-29 13:24:48.675926 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/101@thecarmel.uphone.ca) State CONSUME_MEDIA going to sleep
2018-08-29 13:24:48.675926 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f67a409d500 Connected.
2018-08-29 13:24:48.675926 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f679012a2c0 Connected.
2018-08-29 13:24:48.675926 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f679012a2c0 released.
2018-08-29 13:24:48.675926 [NOTICE] switch_cpp.cpp:1365 [xml_handler] local_hostname: voip-ss-001.uphone.ca database_hostname: voip-ss-002.uphone.ca dial_string: {sip_h_X-context=thecarmel.uphone.ca,sip_invite_domain=thecarmel.uphone.ca,presence_id=105@thecarmel.uphone.ca}sofia/internal/105@thecarmel.uphone.ca;fs_path=sip:voip-ss-002.uphone.ca
2018-08-29 13:24:48.695926 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f67a409d500 released.
2018-08-29 13:24:48.695926 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [effective_caller_id_name]=[Adrien Alexson] to event
2018-08-29 13:24:48.695926 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [caller_id_name]=[Adrien Alexson] to event
2018-08-29 13:24:48.695926 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [origination_callee_id_name]=[4200] to event
2018-08-29 13:24:48.695926 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [origination_callee_id_name]=[4200] to event
2018-08-29 13:24:48.695926 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [origination_callee_id_name]=[4200] to event
2018-08-29 13:24:48.695926 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2018-08-29 13:24:48.695926 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/105@thecarmel.uphone.ca [51dd5bcf-68c7-4b70-b70d-4d5d6ee23273]
2018-08-29 13:24:48.695926 [DEBUG] mod_sofia.c:4818 (sofia/internal/105@thecarmel.uphone.ca) State Change CS_NEW -> CS_INIT
2018-08-29 13:24:48.695926 [DEBUG] switch_ivr_originate.c:2957 sofia/internal/105@thecarmel.uphone.ca Setting leg timeout to 25
2018-08-29 13:24:48.695926 [DEBUG] switch_ivr_originate.c:2957 sofia/internal/105@thecarmel.uphone.ca Setting leg timeout to 25
2018-08-29 13:24:48.695926 [DEBUG] switch_ivr_originate.c:2663 Parsing session specific variables
2018-08-29 13:24:48.695926 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/105@thecarmel.uphone.ca) Running State Change CS_INIT (Cur 4 Tot 46970)
2018-08-29 13:24:48.695926 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/105@thecarmel.uphone.ca) State INIT
2018-08-29 13:24:48.695926 [DEBUG] mod_sofia.c:90 sofia/internal/105@thecarmel.uphone.ca SOFIA INIT
2018-08-29 13:24:48.695926 [DEBUG] sofia_glue.c:1264 sip:voip-ss-002.uphone.ca Setting proxy route to sofia/internal/105@thecarmel.uphone.ca
2018-08-29 13:24:48.695926 [DEBUG] sofia_glue.c:1295 sofia/internal/105@thecarmel.uphone.ca sending invite version: 1.6.16  64bit
Local SDP:
v=0
o=FreeSWITCH 1535530884 1535530885 IN IP4 208.90.97.6
s=FreeSWITCH
c=IN IP4 208.90.97.6
t=0 0
m=audio 32604 RTP/AVP 0 8 18 3 102 101 13 103 104
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:3 GSM/8000
a=rtpmap:102 opus/48000/2
a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:103 telephone-event/48000
a=fmtp:103 0-16
a=rtcp-mux
a=rtcp:32604 IN IP4 208.90.97.6
a=rtpmap:13 CN/8000
a=rtpmap:104 CN/48000
a=ptime:20
a=sendrecv

2018-08-29 13:24:48.695926 [DEBUG] switch_core_state_machine.c:40 sofia/internal/105@thecarmel.uphone.ca Standard INIT
2018-08-29 13:24:48.695926 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/105@thecarmel.uphone.ca) State Change CS_INIT -> CS_ROUTING
2018-08-29 13:24:48.695926 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/105@thecarmel.uphone.ca) State INIT going to sleep
2018-08-29 13:24:48.695926 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/105@thecarmel.uphone.ca) Running State Change CS_ROUTING (Cur 4 Tot 46970)
2018-08-29 13:24:48.695926 [DEBUG] sofia.c:7048 Channel sofia/internal/105@thecarmel.uphone.ca entering state [calling][0]
2018-08-29 13:24:48.695926 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/105@thecarmel.uphone.ca) State ROUTING
2018-08-29 13:24:48.695926 [DEBUG] mod_sofia.c:143 sofia/internal/105@thecarmel.uphone.ca SOFIA ROUTING
2018-08-29 13:24:48.695926 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/105@thecarmel.uphone.ca) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2018-08-29 13:24:48.695926 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/105@thecarmel.uphone.ca) State ROUTING going to sleep
2018-08-29 13:24:48.695926 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/105@thecarmel.uphone.ca) Running State Change CS_CONSUME_MEDIA (Cur 4 Tot 46970)
2018-08-29 13:24:48.695926 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/105@thecarmel.uphone.ca) State CONSUME_MEDIA
2018-08-29 13:24:48.695926 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/105@thecarmel.uphone.ca) State CONSUME_MEDIA going to sleep
2018-08-29 13:24:48.695926 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f67a409d500 Connected.
2018-08-29 13:24:48.695926 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f679012a2c0 Connected.
2018-08-29 13:24:48.695926 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f679012a2c0 released.
2018-08-29 13:24:48.695926 [NOTICE] switch_cpp.cpp:1365 [xml_handler] local_hostname: voip-ss-001.uphone.ca database_hostname: voip-ss-002.uphone.ca dial_string: {sip_h_X-context=thecarmel.uphone.ca,sip_invite_domain=thecarmel.uphone.ca,presence_id=106@thecarmel.uphone.ca}sofia/internal/106@thecarmel.uphone.ca;fs_path=sip:voip-ss-002.uphone.ca
2018-08-29 13:24:48.715929 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f67a409d500 released.
2018-08-29 13:24:48.715929 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [effective_caller_id_name]=[Adrien Alexson] to event
2018-08-29 13:24:48.715929 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [caller_id_name]=[Adrien Alexson] to event
2018-08-29 13:24:48.715929 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [origination_callee_id_name]=[4200] to event
2018-08-29 13:24:48.715929 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [origination_callee_id_name]=[4200] to event
2018-08-29 13:24:48.715929 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [origination_callee_id_name]=[4200] to event
2018-08-29 13:24:48.715929 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2018-08-29 13:24:48.715929 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/106@thecarmel.uphone.ca [ec5cab3e-d4ba-474f-a3ff-211ecd2e2626]
2018-08-29 13:24:48.715929 [DEBUG] mod_sofia.c:4818 (sofia/internal/106@thecarmel.uphone.ca) State Change CS_NEW -> CS_INIT
2018-08-29 13:24:48.715929 [DEBUG] switch_ivr_originate.c:2957 sofia/internal/106@thecarmel.uphone.ca Setting leg timeout to 25
2018-08-29 13:24:48.715929 [DEBUG] switch_ivr_originate.c:2957 sofia/internal/106@thecarmel.uphone.ca Setting leg timeout to 25
2018-08-29 13:24:48.715929 [DEBUG] switch_ivr_originate.c:2663 Parsing session specific variables
2018-08-29 13:24:48.715929 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/106@thecarmel.uphone.ca) Running State Change CS_INIT (Cur 5 Tot 46971)
2018-08-29 13:24:48.715929 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/106@thecarmel.uphone.ca) State INIT
2018-08-29 13:24:48.715929 [DEBUG] mod_sofia.c:90 sofia/internal/106@thecarmel.uphone.ca SOFIA INIT
2018-08-29 13:24:48.715929 [DEBUG] sofia_glue.c:1264 sip:voip-ss-002.uphone.ca Setting proxy route to sofia/internal/106@thecarmel.uphone.ca
2018-08-29 13:24:48.715929 [DEBUG] sofia_glue.c:1295 sofia/internal/106@thecarmel.uphone.ca sending invite version: 1.6.16  64bit
Local SDP:
v=0
o=FreeSWITCH 1535546952 1535546953 IN IP4 208.90.97.6
s=FreeSWITCH
c=IN IP4 208.90.97.6
t=0 0
m=audio 16536 RTP/AVP 0 8 18 3 102 101 13 103 104
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:3 GSM/8000
a=rtpmap:102 opus/48000/2
a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:103 telephone-event/48000
a=fmtp:103 0-16
a=rtcp-mux
a=rtcp:16536 IN IP4 208.90.97.6
a=rtpmap:13 CN/8000
a=rtpmap:104 CN/48000
a=ptime:20
a=sendrecv

2018-08-29 13:24:48.715929 [DEBUG] switch_core_state_machine.c:40 sofia/internal/106@thecarmel.uphone.ca Standard INIT
2018-08-29 13:24:48.715929 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/106@thecarmel.uphone.ca) State Change CS_INIT -> CS_ROUTING
2018-08-29 13:24:48.715929 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/106@thecarmel.uphone.ca) State INIT going to sleep
2018-08-29 13:24:48.715929 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/106@thecarmel.uphone.ca) Running State Change CS_ROUTING (Cur 5 Tot 46971)
2018-08-29 13:24:48.715929 [DEBUG] sofia.c:7048 Channel sofia/internal/106@thecarmel.uphone.ca entering state [calling][0]
2018-08-29 13:24:48.715929 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/106@thecarmel.uphone.ca) State ROUTING
2018-08-29 13:24:48.715929 [DEBUG] mod_sofia.c:143 sofia/internal/106@thecarmel.uphone.ca SOFIA ROUTING
2018-08-29 13:24:48.715929 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/106@thecarmel.uphone.ca) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2018-08-29 13:24:48.715929 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/106@thecarmel.uphone.ca) State ROUTING going to sleep
2018-08-29 13:24:48.715929 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/106@thecarmel.uphone.ca) Running State Change CS_CONSUME_MEDIA (Cur 5 Tot 46971)
2018-08-29 13:24:48.715929 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/106@thecarmel.uphone.ca) State CONSUME_MEDIA
2018-08-29 13:24:48.715929 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/106@thecarmel.uphone.ca) State CONSUME_MEDIA going to sleep
2018-08-29 13:24:48.715929 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f67a409d500 Connected.
2018-08-29 13:24:48.715929 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f679012a2c0 Connected.
2018-08-29 13:24:48.715929 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f679012a2c0 released.
2018-08-29 13:24:48.735931 [NOTICE] switch_cpp.cpp:1365 [xml_handler] local_hostname: voip-ss-001.uphone.ca database_hostname: voip-ss-002.uphone.ca dial_string: {sip_h_X-context=thecarmel.uphone.ca,sip_invite_domain=thecarmel.uphone.ca,presence_id=107@thecarmel.uphone.ca}sofia/internal/107@thecarmel.uphone.ca;fs_path=sip:voip-ss-002.uphone.ca
2018-08-29 13:24:48.735931 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f67a409d500 released.
2018-08-29 13:24:48.735931 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [effective_caller_id_name]=[Adrien Alexson] to event
2018-08-29 13:24:48.735931 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [caller_id_name]=[Adrien Alexson] to event
2018-08-29 13:24:48.735931 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [origination_callee_id_name]=[4200] to event
2018-08-29 13:24:48.735931 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [origination_callee_id_name]=[4200] to event
2018-08-29 13:24:48.735931 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [origination_callee_id_name]=[4200] to event
2018-08-29 13:24:48.735931 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2018-08-29 13:24:48.735931 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/107@thecarmel.uphone.ca [0aebce17-2c7c-44a6-bfc8-e4b2668a496c]
2018-08-29 13:24:48.735931 [DEBUG] mod_sofia.c:4818 (sofia/internal/107@thecarmel.uphone.ca) State Change CS_NEW -> CS_INIT
2018-08-29 13:24:48.735931 [DEBUG] switch_ivr_originate.c:2957 sofia/internal/107@thecarmel.uphone.ca Setting leg timeout to 25
2018-08-29 13:24:48.735931 [DEBUG] switch_ivr_originate.c:2957 sofia/internal/107@thecarmel.uphone.ca Setting leg timeout to 25
2018-08-29 13:24:48.735931 [DEBUG] switch_ivr_originate.c:2663 Parsing session specific variables
2018-08-29 13:24:48.735931 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/107@thecarmel.uphone.ca) Running State Change CS_INIT (Cur 6 Tot 46972)
2018-08-29 13:24:48.735931 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/107@thecarmel.uphone.ca) State INIT
2018-08-29 13:24:48.735931 [DEBUG] mod_sofia.c:90 sofia/internal/107@thecarmel.uphone.ca SOFIA INIT
2018-08-29 13:24:48.735931 [DEBUG] sofia_glue.c:1264 sip:voip-ss-002.uphone.ca Setting proxy route to sofia/internal/107@thecarmel.uphone.ca
2018-08-29 13:24:48.735931 [DEBUG] sofia_glue.c:1295 sofia/internal/107@thecarmel.uphone.ca sending invite version: 1.6.16  64bit
Local SDP:
v=0
o=FreeSWITCH 1535532006 1535532007 IN IP4 208.90.97.6
s=FreeSWITCH
c=IN IP4 208.90.97.6
t=0 0
m=audio 31482 RTP/AVP 0 8 18 3 102 101 13 103 104
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:3 GSM/8000
a=rtpmap:102 opus/48000/2
a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:103 telephone-event/48000
a=fmtp:103 0-16
a=rtcp-mux
a=rtcp:31482 IN IP4 208.90.97.6
a=rtpmap:13 CN/8000
a=rtpmap:104 CN/48000
a=ptime:20
a=sendrecv

2018-08-29 13:24:48.735931 [DEBUG] switch_core_state_machine.c:40 sofia/internal/107@thecarmel.uphone.ca Standard INIT
2018-08-29 13:24:48.735931 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/107@thecarmel.uphone.ca) State Change CS_INIT -> CS_ROUTING
2018-08-29 13:24:48.735931 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/107@thecarmel.uphone.ca) State INIT going to sleep
2018-08-29 13:24:48.735931 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/107@thecarmel.uphone.ca) Running State Change CS_ROUTING (Cur 6 Tot 46972)
2018-08-29 13:24:48.735931 [DEBUG] sofia.c:7048 Channel sofia/internal/107@thecarmel.uphone.ca entering state [calling][0]
2018-08-29 13:24:48.735931 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/107@thecarmel.uphone.ca) State ROUTING
2018-08-29 13:24:48.735931 [DEBUG] mod_sofia.c:143 sofia/internal/107@thecarmel.uphone.ca SOFIA ROUTING
2018-08-29 13:24:48.735931 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/107@thecarmel.uphone.ca) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2018-08-29 13:24:48.735931 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/107@thecarmel.uphone.ca) State ROUTING going to sleep
2018-08-29 13:24:48.735931 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/107@thecarmel.uphone.ca) Running State Change CS_CONSUME_MEDIA (Cur 6 Tot 46972)
2018-08-29 13:24:48.735931 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/107@thecarmel.uphone.ca) State CONSUME_MEDIA
2018-08-29 13:24:48.735931 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/107@thecarmel.uphone.ca) State CONSUME_MEDIA going to sleep
2018-08-29 13:24:48.735931 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f67a409d500 Connected.
2018-08-29 13:24:48.735931 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f679012a2c0 Connected.
2018-08-29 13:24:48.755928 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f679012a2c0 released.
2018-08-29 13:24:48.755928 [NOTICE] switch_cpp.cpp:1365 [xml_handler] local_hostname: voip-ss-001.uphone.ca database_hostname: voip-ss-002.uphone.ca dial_string: {sip_h_X-context=thecarmel.uphone.ca,sip_invite_domain=thecarmel.uphone.ca,presence_id=108@thecarmel.uphone.ca}sofia/internal/108@thecarmel.uphone.ca;fs_path=sip:voip-ss-002.uphone.ca
2018-08-29 13:24:48.755928 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f67a409d500 released.
2018-08-29 13:24:48.755928 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [effective_caller_id_name]=[Adrien Alexson] to event
2018-08-29 13:24:48.755928 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [caller_id_name]=[Adrien Alexson] to event
2018-08-29 13:24:48.755928 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [origination_callee_id_name]=[4200] to event
2018-08-29 13:24:48.755928 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [origination_callee_id_name]=[4200] to event
2018-08-29 13:24:48.755928 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [origination_callee_id_name]=[4200] to event
2018-08-29 13:24:48.755928 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2018-08-29 13:24:48.755928 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/108@thecarmel.uphone.ca [fb4695bb-d44f-49bf-9e68-5a2a35dedc2e]
2018-08-29 13:24:48.755928 [DEBUG] mod_sofia.c:4818 (sofia/internal/108@thecarmel.uphone.ca) State Change CS_NEW -> CS_INIT
2018-08-29 13:24:48.755928 [DEBUG] switch_ivr_originate.c:2957 sofia/internal/108@thecarmel.uphone.ca Setting leg timeout to 25
2018-08-29 13:24:48.755928 [DEBUG] switch_ivr_originate.c:2957 sofia/internal/108@thecarmel.uphone.ca Setting leg timeout to 25
2018-08-29 13:24:48.755928 [DEBUG] switch_ivr_originate.c:2663 Parsing session specific variables
2018-08-29 13:24:48.755928 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/108@thecarmel.uphone.ca) Running State Change CS_INIT (Cur 7 Tot 46973)
2018-08-29 13:24:48.755928 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/108@thecarmel.uphone.ca) State INIT
2018-08-29 13:24:48.755928 [DEBUG] mod_sofia.c:90 sofia/internal/108@thecarmel.uphone.ca SOFIA INIT
2018-08-29 13:24:48.755928 [DEBUG] sofia_glue.c:1264 sip:voip-ss-002.uphone.ca Setting proxy route to sofia/internal/108@thecarmel.uphone.ca
2018-08-29 13:24:48.755928 [DEBUG] sofia_glue.c:1295 sofia/internal/108@thecarmel.uphone.ca sending invite version: 1.6.16  64bit
Local SDP:
v=0
o=FreeSWITCH 1535538928 1535538929 IN IP4 208.90.97.6
s=FreeSWITCH
c=IN IP4 208.90.97.6
t=0 0
m=audio 24560 RTP/AVP 0 8 18 3 102 101 13 103 104
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:3 GSM/8000
a=rtpmap:102 opus/48000/2
a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:103 telephone-event/48000
a=fmtp:103 0-16
a=rtcp-mux
a=rtcp:24560 IN IP4 208.90.97.6
a=rtpmap:13 CN/8000
a=rtpmap:104 CN/48000
a=ptime:20
a=sendrecv

2018-08-29 13:24:48.755928 [DEBUG] switch_core_state_machine.c:40 sofia/internal/108@thecarmel.uphone.ca Standard INIT
2018-08-29 13:24:48.755928 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/108@thecarmel.uphone.ca) State Change CS_INIT -> CS_ROUTING
2018-08-29 13:24:48.755928 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/108@thecarmel.uphone.ca) State INIT going to sleep
2018-08-29 13:24:48.755928 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/108@thecarmel.uphone.ca) Running State Change CS_ROUTING (Cur 7 Tot 46973)
2018-08-29 13:24:48.755928 [DEBUG] sofia.c:7048 Channel sofia/internal/108@thecarmel.uphone.ca entering state [calling][0]
2018-08-29 13:24:48.755928 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/108@thecarmel.uphone.ca) State ROUTING
2018-08-29 13:24:48.755928 [DEBUG] mod_sofia.c:143 sofia/internal/108@thecarmel.uphone.ca SOFIA ROUTING
2018-08-29 13:24:48.755928 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/108@thecarmel.uphone.ca) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2018-08-29 13:24:48.755928 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/108@thecarmel.uphone.ca) State ROUTING going to sleep
2018-08-29 13:24:48.755928 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/108@thecarmel.uphone.ca) Running State Change CS_CONSUME_MEDIA (Cur 7 Tot 46973)
2018-08-29 13:24:48.755928 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/108@thecarmel.uphone.ca) State CONSUME_MEDIA
2018-08-29 13:24:48.755928 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/108@thecarmel.uphone.ca) State CONSUME_MEDIA going to sleep
2018-08-29 13:24:48.755928 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f67a409d500 Connected.
2018-08-29 13:24:48.755928 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f679012a2c0 Connected.
2018-08-29 13:24:48.775928 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f679012a2c0 released.
2018-08-29 13:24:48.775928 [NOTICE] switch_cpp.cpp:1365 [xml_handler] local_hostname: voip-ss-001.uphone.ca database_hostname: voip-ss-002.uphone.ca dial_string: {sip_h_X-context=thecarmel.uphone.ca,sip_invite_domain=thecarmel.uphone.ca,presence_id=109@thecarmel.uphone.ca}sofia/internal/109@thecarmel.uphone.ca;fs_path=sip:voip-ss-002.uphone.ca
2018-08-29 13:24:48.775928 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f67a409d500 released.
2018-08-29 13:24:48.775928 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [effective_caller_id_name]=[Adrien Alexson] to event
2018-08-29 13:24:48.775928 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [caller_id_name]=[Adrien Alexson] to event
2018-08-29 13:24:48.775928 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [origination_callee_id_name]=[4200] to event
2018-08-29 13:24:48.775928 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [origination_callee_id_name]=[4200] to event
2018-08-29 13:24:48.775928 [DEBUG] switch_channel.c:1250 sofia/external/5195752944@208.89.129.46 EXPORTING[export_vars] [origination_callee_id_name]=[4200] to event
2018-08-29 13:24:48.775928 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2018-08-29 13:24:48.775928 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/109@thecarmel.uphone.ca [99509b40-b4e4-4c53-a9cb-b1daf622751e]
2018-08-29 13:24:48.775928 [DEBUG] mod_sofia.c:4818 (sofia/internal/109@thecarmel.uphone.ca) State Change CS_NEW -> CS_INIT
2018-08-29 13:24:48.775928 [DEBUG] switch_ivr_originate.c:2957 sofia/internal/109@thecarmel.uphone.ca Setting leg timeout to 25
2018-08-29 13:24:48.775928 [DEBUG] switch_ivr_originate.c:2957 sofia/internal/109@thecarmel.uphone.ca Setting leg timeout to 25
2018-08-29 13:24:48.775928 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/109@thecarmel.uphone.ca) Running State Change CS_INIT (Cur 8 Tot 46974)
2018-08-29 13:24:48.775928 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/109@thecarmel.uphone.ca) State INIT
2018-08-29 13:24:48.775928 [DEBUG] mod_sofia.c:90 sofia/internal/109@thecarmel.uphone.ca SOFIA INIT
2018-08-29 13:24:48.775928 [DEBUG] sofia_glue.c:1264 sip:voip-ss-002.uphone.ca Setting proxy route to sofia/internal/109@thecarmel.uphone.ca
2018-08-29 13:24:48.775928 [DEBUG] sofia_glue.c:1295 sofia/internal/109@thecarmel.uphone.ca sending invite version: 1.6.16  64bit
Local SDP:
v=0
o=FreeSWITCH 1535543610 1535543611 IN IP4 208.90.97.6
s=FreeSWITCH
c=IN IP4 208.90.97.6
t=0 0
m=audio 19878 RTP/AVP 0 8 18 3 102 101 13 103 104
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:3 GSM/8000
a=rtpmap:102 opus/48000/2
a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:103 telephone-event/48000
a=fmtp:103 0-16
a=rtcp-mux
a=rtcp:19878 IN IP4 208.90.97.6
a=rtpmap:13 CN/8000
a=rtpmap:104 CN/48000
a=ptime:20
a=sendrecv

2018-08-29 13:24:48.775928 [DEBUG] switch_core_state_machine.c:40 sofia/internal/109@thecarmel.uphone.ca Standard INIT
2018-08-29 13:24:48.775928 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/109@thecarmel.uphone.ca) State Change CS_INIT -> CS_ROUTING
2018-08-29 13:24:48.775928 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/109@thecarmel.uphone.ca) State INIT going to sleep
2018-08-29 13:24:48.775928 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/109@thecarmel.uphone.ca) Running State Change CS_ROUTING (Cur 8 Tot 46974)
2018-08-29 13:24:48.775928 [DEBUG] sofia.c:7048 Channel sofia/internal/109@thecarmel.uphone.ca entering state [calling][0]
2018-08-29 13:24:48.775928 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/109@thecarmel.uphone.ca) State ROUTING
2018-08-29 13:24:48.775928 [DEBUG] mod_sofia.c:143 sofia/internal/109@thecarmel.uphone.ca SOFIA ROUTING
2018-08-29 13:24:48.775928 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/109@thecarmel.uphone.ca) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2018-08-29 13:24:48.775928 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/109@thecarmel.uphone.ca) State ROUTING going to sleep
2018-08-29 13:24:48.775928 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/109@thecarmel.uphone.ca) Running State Change CS_CONSUME_MEDIA (Cur 8 Tot 46974)
2018-08-29 13:24:48.775928 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/109@thecarmel.uphone.ca) State CONSUME_MEDIA
2018-08-29 13:24:48.775928 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/109@thecarmel.uphone.ca) State CONSUME_MEDIA going to sleep
2018-08-29 13:24:49.236044 [INFO] sofia.c:1279 sofia/internal/101@thecarmel.uphone.ca Update Callee ID to "101" <sip:101@thecarmel.uphone.ca>
2018-08-29 13:24:49.236044 [DEBUG] sofia.c:7048 Channel sofia/internal/101@thecarmel.uphone.ca entering state [proceeding][183]
2018-08-29 13:24:49.236044 [DEBUG] sofia.c:7058 Remote SDP:
v=0
o=FreeSWITCH 1535536337 1535536338 IN IP4 208.90.97.9
s=FreeSWITCH
c=IN IP4 208.90.97.9
t=0 0
m=audio 27152 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=rtcp-mux
a=rtcp:27152 IN IP4 208.90.97.9

2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4484 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4345 Set telephone-event payload to 101@8000
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:3049 Set Codec sofia/internal/101@thecarmel.uphone.ca PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2018-08-29 13:24:49.236044 [DEBUG] switch_core_codec.c:111 sofia/internal/101@thecarmel.uphone.ca Original read codec set to PCMU:0
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4688 Set telephone-event payload to 101@8000
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4747 sofia/internal/101@thecarmel.uphone.ca Set 2833 dtmf send payload to 101 recv payload to 101
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:6803 AUDIO RTP [sofia/internal/101@thecarmel.uphone.ca] 208.90.97.6 port 22524 -> 208.90.97.9 port 27152 codec: 0 ms: 20
2018-08-29 13:24:49.236044 [DEBUG] switch_rtp.c:4095 Starting timer [soft] 160 bytes per 20ms
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:7028 Activating RTCP PORT 27152
2018-08-29 13:24:49.236044 [DEBUG] switch_rtp.c:4487 RTCP send rate is: 5000 and packet rate is: 20000 Remote Port: 27152
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:7109 sofia/internal/101@thecarmel.uphone.ca Set 2833 dtmf send payload to 101
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:7116 sofia/internal/101@thecarmel.uphone.ca Set 2833 dtmf receive payload to 101
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:7139 sofia/internal/101@thecarmel.uphone.ca Set rtp dtmf delay to 40
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:7145 Set comfort noise payload to 13
2018-08-29 13:24:49.236044 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/101@thecarmel.uphone.ca!
2018-08-29 13:24:49.236044 [DEBUG] switch_channel.c:3473 (sofia/internal/101@thecarmel.uphone.ca) Callstate Change DOWN -> EARLY
2018-08-29 13:24:49.236044 [INFO] switch_ivr_originate.c:1215 Sending early media
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4484 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4484 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4484 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G729:18:8000:20:8000:1]/[GSM:3:8000:20:13200:1]
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1]
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G722:9:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G722:9:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1]
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4345 Set telephone-event payload to 101@8000
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:3049 Set Codec sofia/external/5195752944@208.89.129.46 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2018-08-29 13:24:49.236044 [DEBUG] switch_core_codec.c:111 sofia/external/5195752944@208.89.129.46 Original read codec set to PCMU:0
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4688 Set telephone-event payload to 101@8000
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:4747 sofia/external/5195752944@208.89.129.46 Set 2833 dtmf send payload to 101 recv payload to 101
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:6803 AUDIO RTP [sofia/external/5195752944@208.89.129.46] 208.90.97.6 port 22160 -> 208.89.128.69 port 59728 codec: 0 ms: 20
2018-08-29 13:24:49.236044 [DEBUG] switch_rtp.c:4095 Starting timer [soft] 160 bytes per 20ms
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:7028 Activating RTCP PORT 0
2018-08-29 13:24:49.236044 [DEBUG] switch_rtp.c:4487 RTCP send rate is: 5000 and packet rate is: 20000 Remote Port: 59729
2018-08-29 13:24:49.236044 [DEBUG] switch_rtp.c:2559 Setting RTCP remote addr to 208.89.128.69:59729 2
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:7109 sofia/external/5195752944@208.89.129.46 Set 2833 dtmf send payload to 101
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:7116 sofia/external/5195752944@208.89.129.46 Set 2833 dtmf receive payload to 101
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:7139 sofia/external/5195752944@208.89.129.46 Set rtp dtmf delay to 40
2018-08-29 13:24:49.236044 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/5195752944@208.89.129.46!
2018-08-29 13:24:49.236044 [DEBUG] switch_channel.c:3473 (sofia/external/5195752944@208.89.129.46) Callstate Change RINGING -> EARLY
2018-08-29 13:24:49.236044 [DEBUG] switch_core_media.c:6786 Audio params are unchanged for sofia/external/5195752944@208.89.129.46.
2018-08-29 13:24:49.236044 [DEBUG] mod_sofia.c:2363 Ring SDP:
v=0
o=FreeSWITCH 1535541329 1535541330 IN IP4 208.90.97.6
s=FreeSWITCH
c=IN IP4 208.90.97.6
t=0 0
m=audio 22160 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
a=rtcp:22161 IN IP4 208.90.97.6

2018-08-29 13:24:49.236044 [DEBUG] switch_ivr_originate.c:1273 Raw Codec Activation Success L16@8000hz 1 channel 20ms
2018-08-29 13:24:49.236044 [DEBUG] switch_core_codec.c:223 sofia/external/5195752944@208.89.129.46 Push codec L16:100
2018-08-29 13:24:49.236044 [DEBUG] switch_ivr_originate.c:1305 Play Ringback File [tone_stream://%(2000, 4000, 440.0, 480.0);loops=-1]
2018-08-29 13:24:49.255938 [DEBUG] sofia.c:7048 Channel sofia/external/5195752944@208.89.129.46 entering state [early][183]
2018-08-29 13:24:49.275954 [INFO] sofia.c:1279 sofia/internal/100@thecarmel.uphone.ca Update Callee ID to "100" <sip:100@thecarmel.uphone.ca>
2018-08-29 13:24:49.275954 [DEBUG] sofia.c:7048 Channel sofia/internal/100@thecarmel.uphone.ca entering state [proceeding][183]
2018-08-29 13:24:49.275954 [DEBUG] sofia.c:7058 Remote SDP:
v=0
o=FreeSWITCH 1535534653 1535534654 IN IP4 208.90.97.9
s=FreeSWITCH
c=IN IP4 208.90.97.9
t=0 0
m=audio 28836 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=rtcp-mux
a=rtcp:28836 IN IP4 208.90.97.9

2018-08-29 13:24:49.275954 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-08-29 13:24:49.275954 [DEBUG] switch_core_media.c:4484 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2018-08-29 13:24:49.275954 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-08-29 13:24:49.275954 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2018-08-29 13:24:49.275954 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2018-08-29 13:24:49.275954 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
2018-08-29 13:24:49.275954 [DEBUG] switch_core_media.c:4345 Set telephone-event payload to 101@8000
2018-08-29 13:24:49.275954 [DEBUG] switch_core_media.c:3049 Set Codec sofia/internal/100@thecarmel.uphone.ca PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2018-08-29 13:24:49.275954 [DEBUG] switch_core_codec.c:111 sofia/internal/100@thecarmel.uphone.ca Original read codec set to PCMU:0
2018-08-29 13:24:49.275954 [DEBUG] switch_core_media.c:4688 Set telephone-event payload to 101@8000
2018-08-29 13:24:49.275954 [DEBUG] switch_core_media.c:4747 sofia/internal/100@thecarmel.uphone.ca Set 2833 dtmf send payload to 101 recv payload to 101
2018-08-29 13:24:49.275954 [DEBUG] switch_core_media.c:6803 AUDIO RTP [sofia/internal/100@thecarmel.uphone.ca] 208.90.97.6 port 30044 -> 208.90.97.9 port 28836 codec: 0 ms: 20
2018-08-29 13:24:49.275954 [DEBUG] switch_rtp.c:4095 Starting timer [soft] 160 bytes per 20ms
2018-08-29 13:24:49.275954 [DEBUG] switch_core_media.c:7028 Activating RTCP PORT 28836
2018-08-29 13:24:49.275954 [DEBUG] switch_rtp.c:4487 RTCP send rate is: 5000 and packet rate is: 20000 Remote Port: 28836
2018-08-29 13:24:49.275954 [DEBUG] switch_core_media.c:7109 sofia/internal/100@thecarmel.uphone.ca Set 2833 dtmf send payload to 101
2018-08-29 13:24:49.275954 [DEBUG] switch_core_media.c:7116 sofia/internal/100@thecarmel.uphone.ca Set 2833 dtmf receive payload to 101
2018-08-29 13:24:49.275954 [DEBUG] switch_core_media.c:7139 sofia/internal/100@thecarmel.uphone.ca Set rtp dtmf delay to 40
2018-08-29 13:24:49.275954 [DEBUG] switch_core_media.c:7145 Set comfort noise payload to 13
2018-08-29 13:24:49.275954 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/100@thecarmel.uphone.ca!
2018-08-29 13:24:49.275954 [DEBUG] switch_channel.c:3473 (sofia/internal/100@thecarmel.uphone.ca) Callstate Change DOWN -> EARLY
2018-08-29 13:24:49.295929 [DEBUG] switch_rtp.c:1884 rtcp_stats_init: audio ssrc[158144313] base_seq[17813]
2018-08-29 13:24:49.295929 [DEBUG] switch_rtp.c:7228 Correct audio ip/port confirmed.
2018-08-29 13:24:49.335934 [INFO] sofia.c:1279 sofia/internal/105@thecarmel.uphone.ca Update Callee ID to "105" <sip:105@thecarmel.uphone.ca>
2018-08-29 13:24:49.335934 [DEBUG] sofia.c:7048 Channel sofia/internal/105@thecarmel.uphone.ca entering state [proceeding][183]
2018-08-29 13:24:49.335934 [DEBUG] sofia.c:7058 Remote SDP:
v=0
o=FreeSWITCH 1535532577 1535532578 IN IP4 208.90.97.9
s=FreeSWITCH
c=IN IP4 208.90.97.9
t=0 0
m=audio 30912 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=rtcp-mux
a=rtcp:30912 IN IP4 208.90.97.9

2018-08-29 13:24:49.335934 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-08-29 13:24:49.335934 [DEBUG] switch_core_media.c:4484 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2018-08-29 13:24:49.335934 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-08-29 13:24:49.335934 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2018-08-29 13:24:49.335934 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2018-08-29 13:24:49.335934 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
2018-08-29 13:24:49.335934 [DEBUG] switch_core_media.c:4345 Set telephone-event payload to 101@8000
2018-08-29 13:24:49.335934 [DEBUG] switch_core_media.c:3049 Set Codec sofia/internal/105@thecarmel.uphone.ca PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2018-08-29 13:24:49.335934 [DEBUG] switch_core_codec.c:111 sofia/internal/105@thecarmel.uphone.ca Original read codec set to PCMU:0
2018-08-29 13:24:49.335934 [DEBUG] switch_core_media.c:4688 Set telephone-event payload to 101@8000
2018-08-29 13:24:49.335934 [DEBUG] switch_core_media.c:4747 sofia/internal/105@thecarmel.uphone.ca Set 2833 dtmf send payload to 101 recv payload to 101
2018-08-29 13:24:49.335934 [DEBUG] switch_core_media.c:6803 AUDIO RTP [sofia/internal/105@thecarmel.uphone.ca] 208.90.97.6 port 32604 -> 208.90.97.9 port 30912 codec: 0 ms: 20
2018-08-29 13:24:49.335934 [DEBUG] switch_rtp.c:4095 Starting timer [soft] 160 bytes per 20ms
2018-08-29 13:24:49.335934 [DEBUG] switch_core_media.c:7028 Activating RTCP PORT 30912
2018-08-29 13:24:49.335934 [DEBUG] switch_rtp.c:4487 RTCP send rate is: 5000 and packet rate is: 20000 Remote Port: 30912
2018-08-29 13:24:49.335934 [DEBUG] switch_core_media.c:7109 sofia/internal/105@thecarmel.uphone.ca Set 2833 dtmf send payload to 101
2018-08-29 13:24:49.335934 [DEBUG] switch_core_media.c:7116 sofia/internal/105@thecarmel.uphone.ca Set 2833 dtmf receive payload to 101
2018-08-29 13:24:49.335934 [DEBUG] switch_core_media.c:7139 sofia/internal/105@thecarmel.uphone.ca Set rtp dtmf delay to 40
2018-08-29 13:24:49.335934 [DEBUG] switch_core_media.c:7145 Set comfort noise payload to 13
2018-08-29 13:24:49.335934 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/105@thecarmel.uphone.ca!
2018-08-29 13:24:49.335934 [DEBUG] switch_channel.c:3473 (sofia/internal/105@thecarmel.uphone.ca) Callstate Change DOWN -> EARLY
2018-08-29 13:24:49.355931 [INFO] sofia.c:1279 sofia/internal/109@thecarmel.uphone.ca Update Callee ID to "109" <sip:109@thecarmel.uphone.ca>
2018-08-29 13:24:49.355931 [INFO] sofia.c:1279 sofia/internal/108@thecarmel.uphone.ca Update Callee ID to "108" <sip:108@thecarmel.uphone.ca>
2018-08-29 13:24:49.355931 [DEBUG] sofia.c:7048 Channel sofia/internal/109@thecarmel.uphone.ca entering state [completing][200]
2018-08-29 13:24:49.355931 [DEBUG] sofia.c:7058 Remote SDP:
v=0
o=FreeSWITCH 1535541505 1535541506 IN IP4 208.90.97.9
s=FreeSWITCH
c=IN IP4 208.90.97.9
t=0 0
m=audio 21984 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=rtcp-mux
a=rtcp:21984 IN IP4 208.90.97.9

2018-08-29 13:24:49.355931 [DEBUG] sofia.c:7048 Channel sofia/internal/109@thecarmel.uphone.ca entering state [ready][200]
2018-08-29 13:24:49.355931 [DEBUG] sofia.c:7048 Channel sofia/internal/108@thecarmel.uphone.ca entering state [proceeding][183]
2018-08-29 13:24:49.355931 [DEBUG] sofia.c:7058 Remote SDP:
v=0
o=FreeSWITCH 1535533763 1535533764 IN IP4 208.90.97.9
s=FreeSWITCH
c=IN IP4 208.90.97.9
t=0 0
m=audio 29726 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=rtcp-mux
a=rtcp:29726 IN IP4 208.90.97.9

2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:4484 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:4345 Set telephone-event payload to 101@8000
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:4484 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G729:18:8000:20:8000:1]
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:3049 Set Codec sofia/internal/108@thecarmel.uphone.ca PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:4429 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
2018-08-29 13:24:49.355931 [DEBUG] switch_core_codec.c:111 sofia/internal/108@thecarmel.uphone.ca Original read codec set to PCMU:0
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:4345 Set telephone-event payload to 101@8000
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:3049 Set Codec sofia/internal/109@thecarmel.uphone.ca PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2018-08-29 13:24:49.355931 [DEBUG] switch_core_codec.c:111 sofia/internal/109@thecarmel.uphone.ca Original read codec set to PCMU:0
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:4688 Set telephone-event payload to 101@8000
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:4747 sofia/internal/109@thecarmel.uphone.ca Set 2833 dtmf send payload to 101 recv payload to 101
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:6803 AUDIO RTP [sofia/internal/109@thecarmel.uphone.ca] 208.90.97.6 port 19878 -> 208.90.97.9 port 21984 codec: 0 ms: 20
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:4688 Set telephone-event payload to 101@8000
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:4747 sofia/internal/108@thecarmel.uphone.ca Set 2833 dtmf send payload to 101 recv payload to 101
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:6803 AUDIO RTP [sofia/internal/108@thecarmel.uphone.ca] 208.90.97.6 port 24560 -> 208.90.97.9 port 29726 codec: 0 ms: 20
2018-08-29 13:24:49.355931 [DEBUG] switch_rtp.c:4095 Starting timer [soft] 160 bytes per 20ms
2018-08-29 13:24:49.355931 [DEBUG] switch_rtp.c:4095 Starting timer [soft] 160 bytes per 20ms
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:7028 Activating RTCP PORT 21984
2018-08-29 13:24:49.355931 [DEBUG] switch_rtp.c:4487 RTCP send rate is: 5000 and packet rate is: 20000 Remote Port: 21984
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:7028 Activating RTCP PORT 29726
2018-08-29 13:24:49.355931 [DEBUG] switch_rtp.c:4487 RTCP send rate is: 5000 and packet rate is: 20000 Remote Port: 29726
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:7109 sofia/internal/109@thecarmel.uphone.ca Set 2833 dtmf send payload to 101
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:7116 sofia/internal/109@thecarmel.uphone.ca Set 2833 dtmf receive payload to 101
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:7139 sofia/internal/109@thecarmel.uphone.ca Set rtp dtmf delay to 40
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:7145 Set comfort noise payload to 13
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:7109 sofia/internal/108@thecarmel.uphone.ca Set 2833 dtmf send payload to 101
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:7116 sofia/internal/108@thecarmel.uphone.ca Set 2833 dtmf receive payload to 101
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:7139 sofia/internal/108@thecarmel.uphone.ca Set rtp dtmf delay to 40
2018-08-29 13:24:49.355931 [DEBUG] switch_core_media.c:7145 Set comfort noise payload to 13
2018-08-29 13:24:49.355931 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/108@thecarmel.uphone.ca!
2018-08-29 13:24:49.355931 [NOTICE] sofia.c:8167 Channel [sofia/internal/109@thecarmel.uphone.ca] has been answered
2018-08-29 13:24:49.355931 [DEBUG] switch_channel.c:3473 (sofia/internal/108@thecarmel.uphone.ca) Callstate Change DOWN -> EARLY
2018-08-29 13:24:49.355931 [DEBUG] switch_channel.c:3772 (sofia/internal/109@thecarmel.uphone.ca) Callstate Change DOWN -> ACTIVE
EXECUTE sofia/internal/109@thecarmel.uphone.ca lua(/usr/share/freeswitch/scripts/confirm.lua)
2018-08-29 13:24:49.355931 [DEBUG] switch_cpp.cpp:1112 sofia/internal/109@thecarmel.uphone.ca destroy/unlink session from object
2018-08-29 13:24:49.375934 [DEBUG] switch_core_codec.c:248 sofia/external/5195752944@208.89.129.46 Restore previous codec PCMU:0.
2018-08-29 13:24:49.375934 [NOTICE] switch_ivr_originate.c:3605 Hangup sofia/internal/100@thecarmel.uphone.ca [CS_CONSUME_MEDIA] [LOSE_RACE]
2018-08-29 13:24:49.375934 [NOTICE] switch_ivr_originate.c:3605 Hangup sofia/internal/101@thecarmel.uphone.ca [CS_CONSUME_MEDIA] [LOSE_RACE]
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/100@thecarmel.uphone.ca) Running State Change CS_HANGUP (Cur 8 Tot 46974)
2018-08-29 13:24:49.375934 [NOTICE] switch_ivr_originate.c:3605 Hangup sofia/internal/105@thecarmel.uphone.ca [CS_CONSUME_MEDIA] [LOSE_RACE]
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/100@thecarmel.uphone.ca) Callstate Change EARLY -> HANGUP
2018-08-29 13:24:49.375934 [NOTICE] switch_ivr_originate.c:3605 Hangup sofia/internal/106@thecarmel.uphone.ca [CS_CONSUME_MEDIA] [LOSE_RACE]
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/100@thecarmel.uphone.ca) State HANGUP
2018-08-29 13:24:49.375934 [DEBUG] mod_sofia.c:438 Channel sofia/internal/100@thecarmel.uphone.ca hanging up, cause: LOSE_RACE
2018-08-29 13:24:49.375934 [NOTICE] switch_ivr_originate.c:3605 Hangup sofia/internal/107@thecarmel.uphone.ca [CS_CONSUME_MEDIA] [LOSE_RACE]
2018-08-29 13:24:49.375934 [NOTICE] switch_ivr_originate.c:3605 Hangup sofia/internal/108@thecarmel.uphone.ca [CS_CONSUME_MEDIA] [LOSE_RACE]
2018-08-29 13:24:49.375934 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/internal/100@thecarmel.uphone.ca
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:60 sofia/internal/100@thecarmel.uphone.ca Standard HANGUP, cause: LOSE_RACE
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/100@thecarmel.uphone.ca) State HANGUP going to sleep
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/100@thecarmel.uphone.ca) State Change CS_HANGUP -> CS_REPORTING
2018-08-29 13:24:49.375934 [DEBUG] switch_core_media.c:6786 Audio params are unchanged for sofia/external/5195752944@208.89.129.46.
2018-08-29 13:24:49.375934 [DEBUG] mod_sofia.c:850 Local SDP sofia/external/5195752944@208.89.129.46:
v=0
o=FreeSWITCH 1535541329 1535541331 IN IP4 208.90.97.6
s=FreeSWITCH
c=IN IP4 208.90.97.6
t=0 0
m=audio 22160 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
a=rtcp:22161 IN IP4 208.90.97.6

2018-08-29 13:24:49.375934 [NOTICE] switch_ivr_originate.c:3632 Channel [sofia/external/5195752944@208.89.129.46] has been answered
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/100@thecarmel.uphone.ca) Running State Change CS_REPORTING (Cur 8 Tot 46974)
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/100@thecarmel.uphone.ca) State REPORTING
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:174 sofia/internal/100@thecarmel.uphone.ca Standard REPORTING, cause: LOSE_RACE
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/100@thecarmel.uphone.ca) State REPORTING going to sleep
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/100@thecarmel.uphone.ca) State Change CS_REPORTING -> CS_DESTROY
2018-08-29 13:24:49.375934 [DEBUG] switch_core_session.c:1664 Session 46968 (sofia/internal/100@thecarmel.uphone.ca) Locked, Waiting on external entities
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/101@thecarmel.uphone.ca) Running State Change CS_HANGUP (Cur 8 Tot 46974)
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/106@thecarmel.uphone.ca) Running State Change CS_HANGUP (Cur 8 Tot 46974)
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/101@thecarmel.uphone.ca) Callstate Change EARLY -> HANGUP
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/101@thecarmel.uphone.ca) State HANGUP
2018-08-29 13:24:49.375934 [DEBUG] mod_sofia.c:438 Channel sofia/internal/101@thecarmel.uphone.ca hanging up, cause: LOSE_RACE
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/106@thecarmel.uphone.ca) Callstate Change DOWN -> HANGUP
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/106@thecarmel.uphone.ca) State HANGUP
2018-08-29 13:24:49.375934 [DEBUG] mod_sofia.c:438 Channel sofia/internal/106@thecarmel.uphone.ca hanging up, cause: LOSE_RACE
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/105@thecarmel.uphone.ca) Running State Change CS_HANGUP (Cur 8 Tot 46974)
2018-08-29 13:24:49.375934 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/internal/101@thecarmel.uphone.ca
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/105@thecarmel.uphone.ca) Callstate Change EARLY -> HANGUP
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:60 sofia/internal/101@thecarmel.uphone.ca Standard HANGUP, cause: LOSE_RACE
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/101@thecarmel.uphone.ca) State HANGUP going to sleep
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/105@thecarmel.uphone.ca) State HANGUP
2018-08-29 13:24:49.375934 [DEBUG] mod_sofia.c:438 Channel sofia/internal/105@thecarmel.uphone.ca hanging up, cause: LOSE_RACE
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/101@thecarmel.uphone.ca) State Change CS_HANGUP -> CS_REPORTING
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/101@thecarmel.uphone.ca) Running State Change CS_REPORTING (Cur 8 Tot 46974)
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/101@thecarmel.uphone.ca) State REPORTING
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:174 sofia/internal/101@thecarmel.uphone.ca Standard REPORTING, cause: LOSE_RACE
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/101@thecarmel.uphone.ca) State REPORTING going to sleep
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/101@thecarmel.uphone.ca) State Change CS_REPORTING -> CS_DESTROY
2018-08-29 13:24:49.375934 [DEBUG] switch_core_session.c:1664 Session 46969 (sofia/internal/101@thecarmel.uphone.ca) Locked, Waiting on external entities
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/107@thecarmel.uphone.ca) Running State Change CS_HANGUP (Cur 8 Tot 46974)
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/108@thecarmel.uphone.ca) Running State Change CS_HANGUP (Cur 8 Tot 46974)
2018-08-29 13:24:49.375934 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/internal/105@thecarmel.uphone.ca
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:60 sofia/internal/105@thecarmel.uphone.ca Standard HANGUP, cause: LOSE_RACE
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/105@thecarmel.uphone.ca) State HANGUP going to sleep
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/105@thecarmel.uphone.ca) State Change CS_HANGUP -> CS_REPORTING
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/108@thecarmel.uphone.ca) Callstate Change EARLY -> HANGUP
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/105@thecarmel.uphone.ca) Running State Change CS_REPORTING (Cur 8 Tot 46974)
2018-08-29 13:24:49.375934 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/108@thecarmel.uphone.ca) State HANGUP
2018-08-29 13:24:49.375934 [DEBUG] mod_sofia.c:438 Channel sofia/internal/108@thecarmel.uphone.ca hanging up, cause: LOSE_RACE
2018-08-29 13:24:49.395934 [DEBUG] switch_channel.c:3772 (sofia/external/5195752944@208.89.129.46) Callstate Change EARLY -> ACTIVE
2018-08-29 13:24:49.395934 [DEBUG] sofia.c:7048 Channel sofia/external/5195752944@208.89.129.46 entering state [completed][200]
2018-08-29 13:24:49.395934 [DEBUG] switch_ivr_originate.c:3690 Originate Resulted in Success: [sofia/internal/109@thecarmel.uphone.ca]
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/105@thecarmel.uphone.ca) State REPORTING
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:174 sofia/internal/105@thecarmel.uphone.ca Standard REPORTING, cause: LOSE_RACE
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/105@thecarmel.uphone.ca) State REPORTING going to sleep
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/105@thecarmel.uphone.ca) State Change CS_REPORTING -> CS_DESTROY
2018-08-29 13:24:49.395934 [DEBUG] switch_core_session.c:1664 Session 46970 (sofia/internal/105@thecarmel.uphone.ca) Locked, Waiting on external entities
2018-08-29 13:24:49.395934 [NOTICE] switch_core_session.c:1682 Session 46970 (sofia/internal/105@thecarmel.uphone.ca) Ended
2018-08-29 13:24:49.395934 [NOTICE] switch_core_session.c:1686 Close Channel sofia/internal/105@thecarmel.uphone.ca [CS_DESTROY]
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/105@thecarmel.uphone.ca) Running State Change CS_DESTROY (Cur 7 Tot 46974)
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/105@thecarmel.uphone.ca) State DESTROY
2018-08-29 13:24:49.395934 [DEBUG] mod_sofia.c:343 sofia/internal/105@thecarmel.uphone.ca SOFIA DESTROY
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:181 sofia/internal/105@thecarmel.uphone.ca Standard DESTROY
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/105@thecarmel.uphone.ca) State DESTROY going to sleep
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/107@thecarmel.uphone.ca) Callstate Change DOWN -> HANGUP
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/107@thecarmel.uphone.ca) State HANGUP
2018-08-29 13:24:49.395934 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/internal/106@thecarmel.uphone.ca
2018-08-29 13:24:49.395934 [DEBUG] mod_sofia.c:438 Channel sofia/internal/107@thecarmel.uphone.ca hanging up, cause: LOSE_RACE
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:60 sofia/internal/106@thecarmel.uphone.ca Standard HANGUP, cause: LOSE_RACE
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/106@thecarmel.uphone.ca) State HANGUP going to sleep
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/106@thecarmel.uphone.ca) State Change CS_HANGUP -> CS_REPORTING
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/106@thecarmel.uphone.ca) Running State Change CS_REPORTING (Cur 7 Tot 46974)
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/106@thecarmel.uphone.ca) State REPORTING
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:174 sofia/internal/106@thecarmel.uphone.ca Standard REPORTING, cause: LOSE_RACE
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/106@thecarmel.uphone.ca) State REPORTING going to sleep
2018-08-29 13:24:49.395934 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/internal/107@thecarmel.uphone.ca
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:60 sofia/internal/107@thecarmel.uphone.ca Standard HANGUP, cause: LOSE_RACE
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/107@thecarmel.uphone.ca) State HANGUP going to sleep
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/107@thecarmel.uphone.ca) State Change CS_HANGUP -> CS_REPORTING
2018-08-29 13:24:49.395934 [NOTICE] switch_core_session.c:1682 Session 46969 (sofia/internal/101@thecarmel.uphone.ca) Ended
2018-08-29 13:24:49.395934 [NOTICE] switch_core_session.c:1686 Close Channel sofia/internal/101@thecarmel.uphone.ca [CS_DESTROY]
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/106@thecarmel.uphone.ca) State Change CS_REPORTING -> CS_DESTROY
2018-08-29 13:24:49.395934 [DEBUG] switch_core_session.c:1664 Session 46971 (sofia/internal/106@thecarmel.uphone.ca) Locked, Waiting on external entities
2018-08-29 13:24:49.395934 [NOTICE] switch_core_session.c:1682 Session 46971 (sofia/internal/106@thecarmel.uphone.ca) Ended
2018-08-29 13:24:49.395934 [NOTICE] switch_core_session.c:1686 Close Channel sofia/internal/106@thecarmel.uphone.ca [CS_DESTROY]
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/101@thecarmel.uphone.ca) Running State Change CS_DESTROY (Cur 5 Tot 46974)
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/106@thecarmel.uphone.ca) Running State Change CS_DESTROY (Cur 5 Tot 46974)
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/101@thecarmel.uphone.ca) State DESTROY
2018-08-29 13:24:49.395934 [DEBUG] mod_sofia.c:343 sofia/internal/101@thecarmel.uphone.ca SOFIA DESTROY
2018-08-29 13:24:49.395934 [NOTICE] switch_core_session.c:1682 Session 46968 (sofia/internal/100@thecarmel.uphone.ca) Ended
2018-08-29 13:24:49.395934 [NOTICE] switch_core_session.c:1686 Close Channel sofia/internal/100@thecarmel.uphone.ca [CS_DESTROY]
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:181 sofia/internal/101@thecarmel.uphone.ca Standard DESTROY
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/101@thecarmel.uphone.ca) State DESTROY going to sleep
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/100@thecarmel.uphone.ca) Running State Change CS_DESTROY (Cur 4 Tot 46974)
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/100@thecarmel.uphone.ca) State DESTROY
2018-08-29 13:24:49.395934 [DEBUG] mod_sofia.c:343 sofia/internal/100@thecarmel.uphone.ca SOFIA DESTROY
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:181 sofia/internal/100@thecarmel.uphone.ca Standard DESTROY
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/100@thecarmel.uphone.ca) State DESTROY going to sleep
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/106@thecarmel.uphone.ca) State DESTROY
2018-08-29 13:24:49.395934 [DEBUG] mod_sofia.c:343 sofia/internal/106@thecarmel.uphone.ca SOFIA DESTROY
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:181 sofia/internal/106@thecarmel.uphone.ca Standard DESTROY
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/106@thecarmel.uphone.ca) State DESTROY going to sleep
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/107@thecarmel.uphone.ca) Running State Change CS_REPORTING (Cur 4 Tot 46974)
2018-08-29 13:24:49.395934 [DEBUG] sofia.c:7048 Channel sofia/external/5195752944@208.89.129.46 entering state [ready][200]
2018-08-29 13:24:49.395934 [DEBUG] mod_sofia.c:502 Sending CANCEL to sofia/internal/108@thecarmel.uphone.ca
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:60 sofia/internal/108@thecarmel.uphone.ca Standard HANGUP, cause: LOSE_RACE
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/108@thecarmel.uphone.ca) State HANGUP going to sleep
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/108@thecarmel.uphone.ca) State Change CS_HANGUP -> CS_REPORTING
2018-08-29 13:24:49.395934 [DEBUG] switch_ivr_bridge.c:1574 (sofia/internal/109@thecarmel.uphone.ca) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/108@thecarmel.uphone.ca) Running State Change CS_REPORTING (Cur 4 Tot 46974)
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/107@thecarmel.uphone.ca) State REPORTING
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:174 sofia/internal/107@thecarmel.uphone.ca Standard REPORTING, cause: LOSE_RACE
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/107@thecarmel.uphone.ca) State REPORTING going to sleep
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/108@thecarmel.uphone.ca) State REPORTING
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/107@thecarmel.uphone.ca) State Change CS_REPORTING -> CS_DESTROY
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:174 sofia/internal/108@thecarmel.uphone.ca Standard REPORTING, cause: LOSE_RACE
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/108@thecarmel.uphone.ca) State REPORTING going to sleep
2018-08-29 13:24:49.395934 [DEBUG] switch_core_session.c:1664 Session 46972 (sofia/internal/107@thecarmel.uphone.ca) Locked, Waiting on external entities
2018-08-29 13:24:49.395934 [NOTICE] switch_core_session.c:1682 Session 46972 (sofia/internal/107@thecarmel.uphone.ca) Ended
2018-08-29 13:24:49.395934 [NOTICE] switch_core_session.c:1686 Close Channel sofia/internal/107@thecarmel.uphone.ca [CS_DESTROY]
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/107@thecarmel.uphone.ca) Running State Change CS_DESTROY (Cur 3 Tot 46974)
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/107@thecarmel.uphone.ca) State DESTROY
2018-08-29 13:24:49.395934 [DEBUG] mod_sofia.c:343 sofia/internal/107@thecarmel.uphone.ca SOFIA DESTROY
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:181 sofia/internal/107@thecarmel.uphone.ca Standard DESTROY
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/107@thecarmel.uphone.ca) State DESTROY going to sleep
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/108@thecarmel.uphone.ca) State Change CS_REPORTING -> CS_DESTROY
2018-08-29 13:24:49.395934 [DEBUG] switch_core_session.c:1664 Session 46973 (sofia/internal/108@thecarmel.uphone.ca) Locked, Waiting on external entities
2018-08-29 13:24:49.395934 [NOTICE] switch_core_session.c:1682 Session 46973 (sofia/internal/108@thecarmel.uphone.ca) Ended
2018-08-29 13:24:49.395934 [NOTICE] switch_core_session.c:1686 Close Channel sofia/internal/108@thecarmel.uphone.ca [CS_DESTROY]
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/108@thecarmel.uphone.ca) Running State Change CS_DESTROY (Cur 2 Tot 46974)
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/108@thecarmel.uphone.ca) State DESTROY
2018-08-29 13:24:49.395934 [DEBUG] mod_sofia.c:343 sofia/internal/108@thecarmel.uphone.ca SOFIA DESTROY
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:181 sofia/internal/108@thecarmel.uphone.ca Standard DESTROY
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/108@thecarmel.uphone.ca) State DESTROY going to sleep
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/109@thecarmel.uphone.ca) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 46974)
2018-08-29 13:24:49.395934 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/109@thecarmel.uphone.ca) State EXCHANGE_MEDIA
2018-08-29 13:24:49.395934 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA
2018-08-29 13:24:49.435932 [DEBUG] switch_rtp.c:7228 Correct audio ip/port confirmed.
2018-08-29 13:24:50.435929 [DEBUG] switch_rtp.c:7228 Correct audio ip/port confirmed.
2018-08-29 13:24:50.455928 [DEBUG] switch_rtp.c:1884 rtcp_stats_init: audio ssrc[1652856672] base_seq[33176]
2018-08-29 13:24:55.515939 [NOTICE] sofia.c:1012 Hangup sofia/internal/109@thecarmel.uphone.ca [CS_EXCHANGE_MEDIA] [NO_ANSWER]
2018-08-29 13:24:55.515939 [DEBUG] switch_ivr_bridge.c:760 BRIDGE THREAD DONE [sofia/internal/109@thecarmel.uphone.ca]
2018-08-29 13:24:55.515939 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/109@thecarmel.uphone.ca) State EXCHANGE_MEDIA going to sleep
2018-08-29 13:24:55.515939 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/109@thecarmel.uphone.ca) Running State Change CS_HANGUP (Cur 2 Tot 46974)
2018-08-29 13:24:55.515939 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/109@thecarmel.uphone.ca) Callstate Change ACTIVE -> HANGUP
2018-08-29 13:24:55.515939 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/109@thecarmel.uphone.ca) State HANGUP
2018-08-29 13:24:55.515939 [DEBUG] mod_sofia.c:438 Channel sofia/internal/109@thecarmel.uphone.ca hanging up, cause: NO_ANSWER
2018-08-29 13:24:55.515939 [DEBUG] switch_core_state_machine.c:60 sofia/internal/109@thecarmel.uphone.ca Standard HANGUP, cause: NO_ANSWER
2018-08-29 13:24:55.515939 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/109@thecarmel.uphone.ca) State HANGUP going to sleep
2018-08-29 13:24:55.515939 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/109@thecarmel.uphone.ca) State Change CS_HANGUP -> CS_REPORTING
2018-08-29 13:24:55.515939 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/109@thecarmel.uphone.ca) Running State Change CS_REPORTING (Cur 2 Tot 46974)
2018-08-29 13:24:55.515939 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/109@thecarmel.uphone.ca) State REPORTING
2018-08-29 13:24:55.515939 [DEBUG] switch_core_state_machine.c:174 sofia/internal/109@thecarmel.uphone.ca Standard REPORTING, cause: NO_ANSWER
2018-08-29 13:24:55.515939 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/109@thecarmel.uphone.ca) State REPORTING going to sleep
2018-08-29 13:24:55.515939 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/109@thecarmel.uphone.ca) State Change CS_REPORTING -> CS_DESTROY
2018-08-29 13:24:55.515939 [DEBUG] switch_core_session.c:1664 Session 46974 (sofia/internal/109@thecarmel.uphone.ca) Locked, Waiting on external entities
2018-08-29 13:24:55.515939 [DEBUG] switch_ivr_bridge.c:681 sofia/internal/109@thecarmel.uphone.ca ending bridge by request from write function
2018-08-29 13:24:55.515939 [DEBUG] switch_ivr_bridge.c:760 BRIDGE THREAD DONE [sofia/external/5195752944@208.89.129.46]
2018-08-29 13:24:55.515939 [NOTICE] switch_ivr_bridge.c:1724 Hangup sofia/external/5195752944@208.89.129.46 [CS_EXECUTE] [NO_ANSWER]
2018-08-29 13:24:55.515939 [NOTICE] switch_core_session.c:1682 Session 46974 (sofia/internal/109@thecarmel.uphone.ca) Ended
2018-08-29 13:24:55.515939 [NOTICE] switch_core_session.c:1686 Close Channel sofia/internal/109@thecarmel.uphone.ca [CS_DESTROY]
2018-08-29 13:24:55.515939 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/109@thecarmel.uphone.ca) Running State Change CS_DESTROY (Cur 1 Tot 46974)
2018-08-29 13:24:55.515939 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/109@thecarmel.uphone.ca) State DESTROY
2018-08-29 13:24:55.515939 [DEBUG] mod_sofia.c:343 sofia/internal/109@thecarmel.uphone.ca SOFIA DESTROY
2018-08-29 13:24:55.515939 [DEBUG] switch_core_state_machine.c:181 sofia/internal/109@thecarmel.uphone.ca Standard DESTROY
2018-08-29 13:24:55.515939 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/109@thecarmel.uphone.ca) State DESTROY going to sleep
2018-08-29 13:24:55.515939 [DEBUG] switch_core_session.c:2814 sofia/external/5195752944@208.89.129.46 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2018-08-29 13:24:55.515939 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f67a409d500 released.
2018-08-29 13:24:55.515939 [DEBUG] switch_cpp.cpp:1112 sofia/external/5195752944@208.89.129.46 destroy/unlink session from object
2018-08-29 13:24:55.515939 [DEBUG] switch_core_session.c:2814 sofia/external/5195752944@208.89.129.46 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2018-08-29 13:24:55.515939 [DEBUG] switch_core_state_machine.c:650 (sofia/external/5195752944@208.89.129.46) State EXECUTE going to sleep
2018-08-29 13:24:55.515939 [DEBUG] switch_core_state_machine.c:584 (sofia/external/5195752944@208.89.129.46) Running State Change CS_HANGUP (Cur 1 Tot 46974)
2018-08-29 13:24:55.515939 [DEBUG] switch_core_state_machine.c:850 (sofia/external/5195752944@208.89.129.46) Callstate Change ACTIVE -> HANGUP
2018-08-29 13:24:55.515939 [DEBUG] switch_core_state_machine.c:852 (sofia/external/5195752944@208.89.129.46) State HANGUP
2018-08-29 13:24:55.515939 [DEBUG] mod_sofia.c:432 sofia/external/5195752944@208.89.129.46 Overriding SIP cause 480 with 200 from the other leg
2018-08-29 13:24:55.515939 [DEBUG] mod_sofia.c:438 Channel sofia/external/5195752944@208.89.129.46 hanging up, cause: NO_ANSWER
2018-08-29 13:24:55.515939 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/external/5195752944@208.89.129.46
2018-08-29 13:24:55.515939 [DEBUG] switch_core_state_machine.c:60 sofia/external/5195752944@208.89.129.46 Standard HANGUP, cause: NO_ANSWER
2018-08-29 13:24:55.515939 [DEBUG] switch_core_state_machine.c:852 (sofia/external/5195752944@208.89.129.46) State HANGUP going to sleep
2018-08-29 13:24:55.515939 [DEBUG] switch_core_state_machine.c:619 (sofia/external/5195752944@208.89.129.46) State Change CS_HANGUP -> CS_REPORTING
2018-08-29 13:24:55.515939 [DEBUG] switch_core_state_machine.c:584 (sofia/external/5195752944@208.89.129.46) Running State Change CS_REPORTING (Cur 1 Tot 46974)
2018-08-29 13:24:55.515939 [DEBUG] switch_core_state_machine.c:938 (sofia/external/5195752944@208.89.129.46) State REPORTING
freeswitch@voip-ss-001.uphone.ca> /exit