[Freeswitch-users] Freeswitch HA sofia recover failing

21 Sep 2016

      We have a two node freeswitch cluster (time is synchronized between both
servers). When we try to recover the call there is no audio, and we get the
following in the log:

2016-09-20 17:37:35.289629 [NOTICE] sofia.c:8062 Hangup sofia/external/
2505555555@456.456.456.456 [CS_RESET] [NORMAL_TEMPORARY_FAILURE]

Any idea what might be wrong?

below are the logs from server a and b ips and dns obfuscated.

SERVER A

2016-09-20 17:37:20.788151 [NOTICE] switch_channel.c:1104 New Channel
sofia/external/2505555555@456.456.456.456 [8e70d2d8-7f93-11e6-a71d-
79c835def150]
2016-09-20 17:37:20.788151 [DEBUG] switch_core_state_machine.c:543
(sofia/external/2505555555@456.456.456.456) Running State Change CS_NEW
2016-09-20 17:37:20.788151 [DEBUG] sofia.c:9587 sofia/external/2505555555
@456.456.456.456 receiving invite from 456.456.456.456:5060 version: 1.7.0
git 7258a24 2016-09-13 18:17:51Z 64bit
2016-09-20 17:37:20.788151 [DEBUG] sofia.c:6963 Channel sofia/external/
2505555555@456.456.456.456 entering state [received][100]
2016-09-20 17:37:20.788151 [DEBUG] sofia.c:6973 Remote SDP:
v=0
o=Itel 15821173 15821173 IN IP4 456.456.456.456
s=Itel
c=IN IP4 456.456.456.456
t=0 0
m=audio 19772 RTP/AVP 0 18 101
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20

2016-09-20 17:37:20.788151 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2016-09-20 17:37:20.788151 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2016-09-20 17:37:20.788151 [DEBUG] switch_core_media.c:4336 Audio Codec
Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2016-09-20 17:37:20.788151 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2016-09-20 17:37:20.788151 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2016-09-20 17:37:20.788151 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
2016-09-20 17:37:20.788151 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2016-09-20 17:37:20.788151 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2016-09-20 17:37:20.788151 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [G729:18:8000:20:8000:1]/[GSM:3:8000:20:13200:1]
2016-09-20 17:37:20.788151 [DEBUG] switch_core_media.c:4197 Set
telephone-event payload to 101@8000
2016-09-20 17:37:20.788151 [DEBUG] switch_core_media.c:3017 Set Codec
sofia/external/2505555555@456.456.456.456 PCMU/8000 20 ms 160 samples 64000
bits 1 channels
2016-09-20 17:37:20.788151 [DEBUG] switch_core_codec.c:111 sofia/external/
2505555555@456.456.456.456 Original read codec set to PCMU:0
2016-09-20 17:37:20.788151 [DEBUG] switch_core_media.c:4542 Set
telephone-event payload to 101@8000
2016-09-20 17:37:20.788151 [DEBUG] switch_core_media.c:4601 sofia/external/
2505555555@456.456.456.456 Set 2833 dtmf send payload to 101 recv payload
to 101
2016-09-20 17:37:20.788151 [DEBUG] sofia.c:7362
(sofia/external/2505555555@456.456.456.456)
State Change CS_NEW -> CS_INIT
2016-09-20 17:37:20.788151 [DEBUG] switch_core_state_machine.c:562
(sofia/external/2505555555@456.456.456.456) State NEW
2016-09-20 17:37:20.788151 [DEBUG] switch_core_state_machine.c:543
(sofia/external/2505555555@456.456.456.456) Running State Change CS_INIT
2016-09-20 17:37:20.788151 [DEBUG] switch_core_state_machine.c:586
(sofia/external/2505555555@456.456.456.456) State INIT
2016-09-20 17:37:20.788151 [DEBUG] mod_sofia.c:90 sofia/external/2505555555
@456.456.456.456 SOFIA INIT
2016-09-20 17:37:20.788151 [DEBUG] switch_core_state_machine.c:40
sofia/external/2505555555@456.456.456.456 Standard INIT
2016-09-20 17:37:20.788151 [DEBUG] switch_core_state_machine.c:48
(sofia/external/2505555555@456.456.456.456) State Change CS_INIT ->
CS_ROUTING
2016-09-20 17:37:20.788151 [DEBUG] switch_core_state_machine.c:586
(sofia/external/2505555555@456.456.456.456) State INIT going to sleep
2016-09-20 17:37:20.788151 [DEBUG] switch_core_state_machine.c:543
(sofia/external/2505555555@456.456.456.456) Running State Change CS_ROUTING
2016-09-20 17:37:20.788151 [DEBUG] switch_channel.c:2249 (sofia/external/
2505555555@456.456.456.456) Callstate Change DOWN -> RINGING
2016-09-20 17:37:20.788151 [DEBUG] switch_core_state_machine.c:602
(sofia/external/2505555555@456.456.456.456) State ROUTING
2016-09-20 17:37:20.788151 [DEBUG] mod_sofia.c:143 sofia/external/2505555555
@456.456.456.456 SOFIA ROUTING
2016-09-20 17:37:20.788151 [DEBUG] switch_core_state_machine.c:236
sofia/external/2505555555@456.456.456.456 Standard ROUTING
2016-09-20 17:37:20.788151 [INFO] mod_dialplan_xml.c:637 Processing
SOKAMLOOPS BC  <2505555555>->7786962265 in context public
Dialplan: sofia/external/2505555555@456.456.456.456 parsing [public->
7786962264] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL) [7786962264]
destination_number(7786962265) =~ /^(7786962264)$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing [public->
7786962265] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS) [7786962265]
destination_number(7786962265) =~ /^(7786962265)$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(call_direction=inbound) INLINE
EXECUTE sofia/external/2505555555@456.456.456.456
set(call_direction=inbound)
2016-09-20 17:37:20.788151 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [call_direction]=[inbound]
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(domain_uuid=a5254a78-db77-4b8c-b333-78d95060f10f) INLINE
EXECUTE sofia/external/2505555555@456.456.456.456
set(domain_uuid=a5254a78-db77-4b8c-b333-78d95060f10f)
2016-09-20 17:37:20.788151 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [domain_uuid]=[a5254a78-db77-
4b8c-b333-78d95060f10f]
Dialplan: sofia/external/2505555555@456.456.456.456 Action set(domain_name=
sipa.test.com) INLINE
EXECUTE sofia/external/2505555555@456.456.456.456 set(domain_name=
sipa.test.com)
2016-09-20 17:37:20.788151 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [domain_name]=[sipa.test.com]
Dialplan: sofia/external/2505555555@456.456.456.456 Action transfer(2001
XML sipa.test.com)
2016-09-20 17:37:20.788151 [DEBUG] switch_core_state_machine.c:286
(sofia/external/2505555555@456.456.456.456) State Change CS_ROUTING ->
CS_EXECUTE
2016-09-20 17:37:20.788151 [DEBUG] switch_core_state_machine.c:602
(sofia/external/2505555555@456.456.456.456) State ROUTING going to sleep
2016-09-20 17:37:20.788151 [DEBUG] switch_core_state_machine.c:543
(sofia/external/2505555555@456.456.456.456) Running State Change CS_EXECUTE
2016-09-20 17:37:20.788151 [DEBUG] switch_core_state_machine.c:609
(sofia/external/2505555555@456.456.456.456) State EXECUTE
2016-09-20 17:37:20.788151 [DEBUG] mod_sofia.c:198 sofia/external/2505555555
@456.456.456.456 SOFIA EXECUTE
2016-09-20 17:37:20.788151 [DEBUG] switch_core_state_machine.c:328
sofia/external/2505555555@456.456.456.456 Standard EXECUTE
EXECUTE sofia/external/2505555555@456.456.456.456 transfer(2001 XML
sipa.test.com)
2016-09-20 17:37:20.788151 [DEBUG] switch_ivr.c:2160 (sofia/external/
2505555555@456.456.456.456) State Change CS_EXECUTE -> CS_ROUTING
2016-09-20 17:37:20.788151 [NOTICE] switch_ivr.c:2167 Transfer
sofia/external/2505555555@456.456.456.456 to XML[2001@sipa.test.com]
2016-09-20 17:37:20.788151 [DEBUG] switch_core_state_machine.c:609
(sofia/external/2505555555@456.456.456.456) State EXECUTE going to sleep
2016-09-20 17:37:20.788151 [DEBUG] switch_core_state_machine.c:543
(sofia/external/2505555555@456.456.456.456) Running State Change CS_ROUTING
2016-09-20 17:37:20.788151 [DEBUG] switch_core_state_machine.c:602
(sofia/external/2505555555@456.456.456.456) State ROUTING
2016-09-20 17:37:20.788151 [DEBUG] mod_sofia.c:143 sofia/external/2505555555
@456.456.456.456 SOFIA ROUTING
2016-09-20 17:37:20.788151 [DEBUG] switch_core_state_machine.c:236
sofia/external/2505555555@456.456.456.456 Standard ROUTING
2016-09-20 17:37:20.788151 [INFO] mod_dialplan_xml.c:637 Processing
SOKAMLOOPS BC  <2505555555>->2001 in context sipa.test.com
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->user_exists] continue=true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[user_exists] () =~ // break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(user_exists=${user_exists id ${destination_number} ${domain_name}})
INLINE
EXECUTE sofia/external/2505555555@456.456.456.456 set(user_exists=true)
2016-09-20 17:37:20.788151 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [user_exists]=[true]
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[user_exists] ${user_exists}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(extension_uuid=${user_data ${destination_number}@${domain_name} var
extension_uuid})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(hold_music=${user_data ${destination_number}@${domain_name} var
hold_music})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(forward_all_enabled=${user_data ${destination_number}@${domain_name}
var forward_all_enabled})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(forward_all_destination=${user_data ${destination_number}@${domain_name}
var forward_all_destination})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(forward_busy_enabled=${user_data ${destination_number}@${domain_name}
var forward_busy_enabled})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(forward_busy_destination=${user_data ${destination_number}@${domain_name}
var forward_busy_destination})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(forward_no_answer_enabled=${user_data ${destination_number}@${domain_name}
var forward_no_answer_enabled})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(forward_no_answer_destination=${user_data
${destination_number}@${domain_name}
var forward_no_answer_destination})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(forward_user_not_registered_enabled=${user_data
${destination_number}@${domain_name}
var forward_user_not_registered_enabled})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(forward_user_not_registered_destination=${user_data
${destination_number}@${domain_name} var forward_user_not_registered_
destination})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(do_not_disturb=${user_data ${destination_number}@${domain_name} var
do_not_disturb})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(call_timeout=${user_data ${destination_number}@${domain_name} var
call_timeout})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(missed_call_app=${user_data ${destination_number}@${domain_name} var
missed_call_app})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(missed_call_data=${user_data ${destination_number}@${domain_name} var
missed_call_data})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(call_screen_enabled=${user_data ${destination_number}@${domain_name}
var call_screen_enabled}) INLINE
EXECUTE sofia/external/2505555555@456.456.456.456
set(call_screen_enabled=false)
2016-09-20 17:37:20.788151 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [call_screen_enabled]=[false]
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->user_exists] continue=true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[user_exists] () =~ // break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(user_exists=${user_exists id ${destination_number} ${domain_name}})
INLINE
EXECUTE sofia/external/2505555555@456.456.456.456 set(user_exists=true)
2016-09-20 17:37:20.788151 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [user_exists]=[true]
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[user_exists] ${user_exists}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(extension_uuid=${user_data ${destination_number}@${domain_name} var
extension_uuid})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(hold_music=${user_data ${destination_number}@${domain_name} var
hold_music})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(forward_all_enabled=${user_data ${destination_number}@${domain_name}
var forward_all_enabled})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(forward_all_destination=${user_data ${destination_number}@${domain_name}
var forward_all_destination})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(forward_busy_enabled=${user_data ${destination_number}@${domain_name}
var forward_busy_enabled})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(forward_busy_destination=${user_data ${destination_number}@${domain_name}
var forward_busy_destination})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(forward_no_answer_enabled=${user_data ${destination_number}@${domain_name}
var forward_no_answer_enabled})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(forward_no_answer_destination=${user_data
${destination_number}@${domain_name}
var forward_no_answer_destination})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(forward_user_not_registered_enabled=${user_data
${destination_number}@${domain_name}
var forward_user_not_registered_enabled})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(forward_user_not_registered_destination=${user_data
${destination_number}@${domain_name} var forward_user_not_registered_
destination})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(do_not_disturb=${user_data ${destination_number}@${domain_name} var
do_not_disturb})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(call_timeout=${user_data ${destination_number}@${domain_name} var
call_timeout})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(missed_call_app=${user_data ${destination_number}@${domain_name} var
missed_call_app})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(missed_call_data=${user_data ${destination_number}@${domain_name} var
missed_call_data})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(call_screen_enabled=${user_data ${destination_number}@${domain_name}
var call_screen_enabled}) INLINE
EXECUTE sofia/external/2505555555@456.456.456.456
set(call_screen_enabled=false)
2016-09-20 17:37:20.788151 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [call_screen_enabled]=[false]
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->call-direction] continue=true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[call-direction] ${call_direction}(inbound) =~ /^(inbound|outbound|local)$/
break=never
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->call-direction] continue=true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[call-direction] ${call_direction}(inbound) =~ /^(inbound|outbound|local)$/
break=never
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->variables] continue=true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[variables] () =~ // break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 Action
export(origination_callee_id_name=${destination_number})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->variables] continue=true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[variables] () =~ // break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 Action
export(origination_callee_id_name=${destination_number})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->user_record] continue=true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[user_record] () =~ // break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(user_record=${user_data ${destination_number}@${domain_name} var
user_record}) INLINE
EXECUTE sofia/external/2505555555@456.456.456.456 set(user_record=)
2016-09-20 17:37:20.788151 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [user_record]=[UNDEF]
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}})
INLINE
2016-09-20 17:37:20.828076 [DEBUG] freeswitch_lua.cpp:365 DBH handle
0x7fa74404e4c0 Connected.
2016-09-20 17:37:20.828076 [DEBUG] freeswitch_lua.cpp:382 DBH handle
0x7fa74404e4c0 released.
EXECUTE sofia/external/2505555555@456.456.456.456
set(from_user_exists=false)
2016-09-20 17:37:20.828076 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [from_user_exists]=[false]
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[user_record] ${user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${user_record}() =~ /^all$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[user_record] ${user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[user_record] ${call_direction}(inbound) =~ /^inbound$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[user_record] ${user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${call_direction}(inbound) =~ /^outbound$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[user_record] ${user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${call_direction}(inbound) =~ /^local$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${user_record}() =~ /^local$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${from_user_record}() =~ /^all$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[user_record] ${call_direction}(inbound) =~ /^inbound$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${from_user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${call_direction}(inbound) =~ /^outbound$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${from_user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${call_direction}(inbound) =~ /^local$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${from_user_record}() =~ /^local$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${record_session}() =~ /^true$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->user_record] continue=true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[user_record] () =~ // break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(user_record=${user_data ${destination_number}@${domain_name} var
user_record}) INLINE
EXECUTE sofia/external/2505555555@456.456.456.456 set(user_record=)
2016-09-20 17:37:20.828076 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [user_record]=[UNDEF]
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}})
INLINE
2016-09-20 17:37:20.828076 [DEBUG] freeswitch_lua.cpp:365 DBH handle
0x7fa74404e4c0 Connected.
2016-09-20 17:37:20.828076 [DEBUG] freeswitch_lua.cpp:382 DBH handle
0x7fa74404e4c0 released.
EXECUTE sofia/external/2505555555@456.456.456.456
set(from_user_exists=false)
2016-09-20 17:37:20.828076 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [from_user_exists]=[false]
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[user_record] ${user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${user_record}() =~ /^all$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[user_record] ${user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[user_record] ${call_direction}(inbound) =~ /^inbound$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[user_record] ${user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${call_direction}(inbound) =~ /^outbound$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[user_record] ${user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${call_direction}(inbound) =~ /^local$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${user_record}() =~ /^local$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${from_user_record}() =~ /^all$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[user_record] ${call_direction}(inbound) =~ /^inbound$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${from_user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${call_direction}(inbound) =~ /^outbound$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${from_user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${call_direction}(inbound) =~ /^local$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${from_user_record}() =~ /^local$/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[user_record] ${record_session}() =~ /^true$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->redial] continue=true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL) [redial]
destination_number(2001) =~ /^(redial|\*870)$/ break=on-true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS) [redial]
() =~ // break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Action
hash(insert/${domain_name}-last_dial/${caller_id_number}/
${destination_number})
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->redial] continue=true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL) [redial]
destination_number(2001) =~ /^(redial|\*870)$/ break=on-true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS) [redial]
() =~ // break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Action
hash(insert/${domain_name}-last_dial/${caller_id_number}/
${destination_number})
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->sbc1.1d10] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[sbc1.1d10] destination_number(2001) =~ /^\+?1?(\d{10})$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->sbc2.1d10] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[sbc2.1d10] destination_number(2001) =~ /^\+?1?(\d{10})$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->agent_status] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[agent_status] destination_number(2001) =~ /^\*22$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->agent_status] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[agent_status] destination_number(2001) =~ /^\*22$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->agent_status_id] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[agent_status_id] destination_number(2001) =~ /^\*23$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->agent_status_id] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[agent_status_id] destination_number(2001) =~ /^\*23$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->group-intercept] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[group-intercept] destination_number(2001) =~ /^\*8$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->group-intercept] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[group-intercept] destination_number(2001) =~ /^\*8$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->page-extension] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[page-extension] destination_number(2001) =~ /^\*8(\d{2,7})$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->page-extension] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[page-extension] destination_number(2001) =~ /^\*8(\d{2,7})$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->eavesdrop] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[eavesdrop] destination_number(2001) =~ /^\*33(\d{2,7})$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->eavesdrop] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[eavesdrop] destination_number(2001) =~ /^\*33(\d{2,7})$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->call_privacy] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[call_privacy] destination_number(2001) =~ /^\*67(\d+)$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->call_privacy] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[call_privacy] destination_number(2001) =~ /^\*67(\d+)$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->call_return] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[call_return] destination_number(2001) =~ /^\*69$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->call_return] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[call_return] destination_number(2001) =~ /^\*69$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->extension_queue] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[extension_queue] destination_number(2001) =~ /^\*800(.*)$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->extension_queue] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[extension_queue] destination_number(2001) =~ /^\*800(.*)$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->intercept-ext] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[intercept-ext] destination_number(2001) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->intercept-ext] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[intercept-ext] destination_number(2001) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->intercept-ext-polycom] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[intercept-ext-polycom] destination_number(2001) =~ /^\*97(\d+)$/
break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->dx] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL) [dx]
destination_number(2001) =~ /^dx$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->dx] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL) [dx]
destination_number(2001) =~ /^dx$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->att_xfer] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL) [att_xfer]
destination_number(2001) =~ /^att_xfer$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->att_xfer] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL) [att_xfer]
destination_number(2001) =~ /^att_xfer$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->extension-to-voicemail] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[extension-to-voicemail] username(2505555555) =~ /^2505555555$/
break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[extension-to-voicemail] destination_number(2001) =~ /^2505555555$/
break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->extension-to-voicemail] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[extension-to-voicemail] username(2505555555) =~ /^2505555555$/
break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[extension-to-voicemail] destination_number(2001) =~ /^2505555555$/
break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->send_to_voicemail] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[send_to_voicemail] destination_number(2001) =~ /^\*99(\d{2,10})$/
break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->send_to_voicemail] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[send_to_voicemail] destination_number(2001) =~ /^\*99(\d{2,10})$/
break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->vmain] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL) [vmain]
destination_number(2001) =~ /^vmain$|^\*4000$|^\*98$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->vmain] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL) [vmain]
destination_number(2001) =~ /^vmain$|^\*4000$|^\*98$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->xfer_vm] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL) [xfer_vm]
destination_number(2001) =~ /^xfer_vm$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->xfer_vm] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL) [xfer_vm]
destination_number(2001) =~ /^xfer_vm$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->is_transfer] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[is_transfer] destination_number(2001) =~ /^is_transfer$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->is_transfer] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[is_transfer] destination_number(2001) =~ /^is_transfer$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->vmain_user] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[vmain_user] destination_number(2001) =~ /^\*97$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->vmain_user] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[vmain_user] destination_number(2001) =~ /^\*97$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->cf] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL) [cf]
destination_number(2001) =~ /^cf$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->cf] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL) [cf]
destination_number(2001) =~ /^cf$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->delay_echo] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[delay_echo] destination_number(2001) =~ /^\*9195$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->delay_echo] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[delay_echo] destination_number(2001) =~ /^\*9195$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->echo] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL) [echo]
destination_number(2001) =~ /^\*9196$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->echo] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL) [echo]
destination_number(2001) =~ /^\*9196$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->is_zrtp_secure] continue=true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[is_zrtp_secure] ${zrtp_secure_media_confirmed}() =~ /^true$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 ANTI-Action
eval(not_secure)
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->is_zrtp_secure] continue=true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[is_zrtp_secure] ${zrtp_secure_media_confirmed}() =~ /^true$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 ANTI-Action
eval(not_secure)
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->milliwatt] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[milliwatt] destination_number(2001) =~ /^\*9197$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->milliwatt] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[milliwatt] destination_number(2001) =~ /^\*9197$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->is_secure] continue=true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[is_secure] ${sip_via_protocol}(udp) =~ /tls/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->is_secure] continue=true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[is_secure] ${sip_via_protocol}(udp) =~ /tls/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->tone_stream] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[tone_stream] destination_number(2001) =~ /^\*9198$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->tone_stream] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[tone_stream] destination_number(2001) =~ /^\*9198$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->hold_music] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[hold_music] destination_number(2001) =~ /^\*9664$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->hold_music] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[hold_music] destination_number(2001) =~ /^\*9664$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->recordings] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[recordings] destination_number(2001) =~ /^\*(732)$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->recordings] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[recordings] destination_number(2001) =~ /^\*(732)$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->directory] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[directory] destination_number(2001) =~ /^\*411$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->directory] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[directory] destination_number(2001) =~ /^\*411$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->wake-up] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL) [wake-up]
destination_number(2001) =~ /^\*(925)$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->wake-up] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL) [wake-up]
destination_number(2001) =~ /^\*(925)$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->valet_park] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[valet_park] destination_number(2001) =~ /^(park\+)?(\*59[0-9][0-9])$/
break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[valet_park] ${sip_h_Referred-By}() =~ /sip:(.*)@.*/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[valet_park] destination_number(2001) =~ /^(park\+)?(\*59[0-9][0-9])$/
break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[valet_park] destination_number(2001) =~ /^(park\+)?(\*59[0-9][0-9])$/
break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->valet_park] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[valet_park] destination_number(2001) =~ /^(park\+)?(\*59[0-9][0-9])$/
break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[valet_park] ${sip_h_Referred-By}() =~ /sip:(.*)@.*/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[valet_park] destination_number(2001) =~ /^(park\+)?(\*59[0-9][0-9])$/
break=never
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[valet_park] destination_number(2001) =~ /^(park\+)?(\*59[0-9][0-9])$/
break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->operator] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL) [operator]
destination_number(2001) =~ /^0$|^operator$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->operator] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL) [operator]
destination_number(2001) =~ /^0$|^operator$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->operator-forward] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[operator-forward] destination_number(2001) =~ /^\*000$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->operator-forward] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[operator-forward] destination_number(2001) =~ /^\*000$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->do-not-disturb] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[do-not-disturb] destination_number(2001) =~ /^\*78$|\*363$/ break=on-true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[do-not-disturb] destination_number(2001) =~ /^\*79$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->do-not-disturb] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[do-not-disturb] destination_number(2001) =~ /^\*78$|\*363$/ break=on-true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[do-not-disturb] destination_number(2001) =~ /^\*79$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->call-forward] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[call-forward] destination_number(2001) =~ /^\*72$/ break=on-true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[call-forward] destination_number(2001) =~ /^\*73$/ break=on-true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[call-forward] destination_number(2001) =~ /^\*74$/ break=on-true
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->call-forward] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[call-forward] destination_number(2001) =~ /^\*72$/ break=on-true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[call-forward] destination_number(2001) =~ /^\*73$/ break=on-true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[call-forward] destination_number(2001) =~ /^\*74$/ break=on-true
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->follow-me] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[follow-me] destination_number(2001) =~ /^\*21$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->follow-me] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[follow-me] destination_number(2001) =~ /^\*21$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->clear_sip_auto_answer] continue=true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[clear_sip_auto_answer] ${click_to_call}() =~ /true/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->clear_sip_auto_answer] continue=true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[clear_sip_auto_answer] ${click_to_call}() =~ /true/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->talking clock date and time] continue=true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL) [talking
clock date and time] destination_number(2001) =~ /^\*9172$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->talking clock time] continue=true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL) [talking
clock time] destination_number(2001) =~ /^\*9170$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->talking clock date] continue=true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL) [talking
clock date] destination_number(2001) =~ /^\*9171$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->call_screen] continue=true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[call_screen] ${call_screen_enabled}(false) =~ /^true$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->call_screen] continue=true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[call_screen] ${call_screen_enabled}(false) =~ /^true$/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->local_extension] continue=true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[local_extension] ${user_exists}(true) =~ /true/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 Action
export(dialed_extension=${destination_number}) INLINE
EXECUTE sofia/external/2505555555@456.456.456.456
export(dialed_extension=2001)
2016-09-20 17:37:20.828076 [DEBUG] switch_channel.c:1296 EXPORT
(export_vars) [dialed_extension]=[2001]
Dialplan: sofia/external/2505555555@456.456.456.456 Action limit(hash
${domain_name} ${destination_number} ${limit_max} ${limit_destination})
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[local_extension] ${sip_authorized}() =~ /true/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 ANTI-Action
set(bind_target=peer) INLINE
EXECUTE sofia/external/2505555555@456.456.456.456 set(bind_target=peer)
2016-09-20 17:37:20.828076 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [bind_target]=[peer]
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[local_extension] () =~ // break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 Action
bind_digit_action(local,*1,exec:execute_extension,dx XML
${context},${bind_target})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
bind_digit_action(local,*2,exec:record_session,${
recordings_dir}/${domain_name}/archive/${strftime(%Y)}/${
strftime(%b)}/${strftime(%d)}/${uuid}.${record_ext},${bind_target})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
bind_digit_action(local,*3,exec:execute_extension,cf XML
${context},${bind_target})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
bind_digit_action(local,*4,exec:execute_extension,att_xfer XML
${context},${bind_target})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
digit_action_set_realm(local)
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[local_extension] () =~ // break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(hangup_after_bridge=true)
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(continue_on_fail=true)
Dialplan: sofia/external/2505555555@456.456.456.456 Action
hash(insert/${domain_name}-call_return/${dialed_
extension}/${caller_id_number})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(called_party_call_group=${user_data(${dialed_extension}@${domain_name}
var call_group)})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
hash(insert/${domain_name}-last_dial/${called_party_call_group}/${uuid})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(api_hangup_hook=lua app.lua hangup)
Dialplan: sofia/external/2505555555@456.456.456.456 Action
bridge(user/${destination_number}@${domain_name})
Dialplan: sofia/external/2505555555@456.456.456.456 Action lua(app.lua
failure_handler)
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->local_extension] continue=true
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[local_extension] ${user_exists}(true) =~ /true/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 Action
export(dialed_extension=${destination_number}) INLINE
EXECUTE sofia/external/2505555555@456.456.456.456
export(dialed_extension=2001)
2016-09-20 17:37:20.828076 [DEBUG] switch_channel.c:1296 EXPORT
(export_vars) [dialed_extension]=[2001]
Dialplan: sofia/external/2505555555@456.456.456.456 Action limit(hash
${domain_name} ${destination_number} ${limit_max} ${limit_destination})
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (FAIL)
[local_extension] ${sip_authorized}() =~ /true/ break=never
Dialplan: sofia/external/2505555555@456.456.456.456 ANTI-Action
set(bind_target=peer) INLINE
EXECUTE sofia/external/2505555555@456.456.456.456 set(bind_target=peer)
2016-09-20 17:37:20.828076 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [bind_target]=[peer]
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[local_extension] () =~ // break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 Action
bind_digit_action(local,*1,exec:execute_extension,dx XML
${context},${bind_target})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
bind_digit_action(local,*2,exec:record_session,${
recordings_dir}/${domain_name}/archive/${strftime(%Y)}/${
strftime(%b)}/${strftime(%d)}/${uuid}.${record_ext},${bind_target})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
bind_digit_action(local,*3,exec:execute_extension,cf XML
${context},${bind_target})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
bind_digit_action(local,*4,exec:execute_extension,att_xfer XML
${context},${bind_target})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
digit_action_set_realm(local)
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[local_extension] () =~ // break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(hangup_after_bridge=true)
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(continue_on_fail=true)
Dialplan: sofia/external/2505555555@456.456.456.456 Action
hash(insert/${domain_name}-call_return/${dialed_
extension}/${caller_id_number})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(called_party_call_group=${user_data(${dialed_extension}@${domain_name}
var call_group)})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
hash(insert/${domain_name}-last_dial/${called_party_call_group}/${uuid})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(api_hangup_hook=lua app.lua hangup)
Dialplan: sofia/external/2505555555@456.456.456.456 Action
bridge(user/${destination_number}@${domain_name})
Dialplan: sofia/external/2505555555@456.456.456.456 Action lua(app.lua
failure_handler)
Dialplan: sofia/external/2505555555@456.456.456.456 parsing
[sipa.test.com->voicemail] continue=false
Dialplan: sofia/external/2505555555@456.456.456.456 Regex (PASS)
[voicemail] ${user_exists}(true) =~ /true/ break=on-false
Dialplan: sofia/external/2505555555@456.456.456.456 Action answer()
Dialplan: sofia/external/2505555555@456.456.456.456 Action sleep(1000)
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(voicemail_action=save)
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(voicemail_id=${destination_number})
Dialplan: sofia/external/2505555555@456.456.456.456 Action
set(voicemail_profile=default)
Dialplan: sofia/external/2505555555@456.456.456.456 Action lua(app.lua
voicemail)
2016-09-20 17:37:20.828076 [DEBUG] switch_core_state_machine.c:286
(sofia/external/2505555555@456.456.456.456) State Change CS_ROUTING ->
CS_EXECUTE
2016-09-20 17:37:20.828076 [DEBUG] switch_core_state_machine.c:602
(sofia/external/2505555555@456.456.456.456) State ROUTING going to sleep
2016-09-20 17:37:20.828076 [DEBUG] switch_core_state_machine.c:543
(sofia/external/2505555555@456.456.456.456) Running State Change CS_EXECUTE
2016-09-20 17:37:20.828076 [DEBUG] switch_core_state_machine.c:609
(sofia/external/2505555555@456.456.456.456) State EXECUTE
2016-09-20 17:37:20.828076 [DEBUG] mod_sofia.c:198 sofia/external/2505555555
@456.456.456.456 SOFIA EXECUTE
2016-09-20 17:37:20.828076 [DEBUG] switch_core_state_machine.c:328
sofia/external/2505555555@456.456.456.456 Standard EXECUTE
EXECUTE sofia/external/2505555555@456.456.456.456
set(extension_uuid=054c1f2c-e5a3-48d3-82f9-7c3b3e9e6367)
2016-09-20 17:37:20.828076 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [extension_uuid]=[054c1f2c-
e5a3-48d3-82f9-7c3b3e9e6367]
EXECUTE sofia/external/2505555555@456.456.456.456
set(hold_music=local_stream://default)
2016-09-20 17:37:20.828076 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [hold_music]=[local_stream://default]
EXECUTE sofia/external/2505555555@456.456.456.456 set(forward_all_enabled=)
2016-09-20 17:37:20.828076 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [forward_all_enabled]=[UNDEF]
EXECUTE sofia/external/2505555555@456.456.456.456
set(forward_all_destination=)
2016-09-20 17:37:20.828076 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [forward_all_destination]=[UNDEF]
EXECUTE sofia/external/2505555555@456.456.456.456 set(forward_busy_enabled=)
2016-09-20 17:37:20.828076 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [forward_busy_enabled]=[UNDEF]
EXECUTE sofia/external/2505555555@456.456.456.456
set(forward_busy_destination=)
2016-09-20 17:37:20.828076 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [forward_busy_destination]=[UNDEF]
EXECUTE sofia/external/2505555555@456.456.456.456
set(forward_no_answer_enabled=)
2016-09-20 17:37:20.848079 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [forward_no_answer_enabled]=[UNDEF]
EXECUTE sofia/external/2505555555@456.456.456.456 set(forward_no_answer_
destination=)
2016-09-20 17:37:20.848079 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [forward_no_answer_destination]=[UNDEF]
EXECUTE sofia/external/2505555555@456.456.456.456 set(forward_user_not_
registered_enabled=)
2016-09-20 17:37:20.848079 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [forward_user_not_registered_enabled]=[UNDEF]
EXECUTE sofia/external/2505555555@456.456.456.456 set(forward_user_not_
registered_destination=)
2016-09-20 17:37:20.848079 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [forward_user_not_registered_destination]=[UNDEF]
EXECUTE sofia/external/2505555555@456.456.456.456 set(do_not_disturb=)
2016-09-20 17:37:20.848079 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [do_not_disturb]=[UNDEF]
EXECUTE sofia/external/2505555555@456.456.456.456 set(call_timeout=30)
2016-09-20 17:37:20.848079 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [call_timeout]=[30]
EXECUTE sofia/external/2505555555@456.456.456.456 set(missed_call_app=)
2016-09-20 17:37:20.848079 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [missed_call_app]=[UNDEF]
EXECUTE sofia/external/2505555555@456.456.456.456 set(missed_call_data=)
2016-09-20 17:37:20.848079 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [missed_call_data]=[UNDEF]
EXECUTE sofia/external/2505555555@456.456.456.456
set(extension_uuid=054c1f2c-e5a3-48d3-82f9-7c3b3e9e6367)
2016-09-20 17:37:20.848079 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [extension_uuid]=[054c1f2c-
e5a3-48d3-82f9-7c3b3e9e6367]
EXECUTE sofia/external/2505555555@456.456.456.456
set(hold_music=local_stream://default)
2016-09-20 17:37:20.848079 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [hold_music]=[local_stream://default]
EXECUTE sofia/external/2505555555@456.456.456.456 set(forward_all_enabled=)
2016-09-20 17:37:20.868076 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [forward_all_enabled]=[UNDEF]
EXECUTE sofia/external/2505555555@456.456.456.456
set(forward_all_destination=)
2016-09-20 17:37:20.868076 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [forward_all_destination]=[UNDEF]
EXECUTE sofia/external/2505555555@456.456.456.456 set(forward_busy_enabled=)
2016-09-20 17:37:20.868076 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [forward_busy_enabled]=[UNDEF]
EXECUTE sofia/external/2505555555@456.456.456.456
set(forward_busy_destination=)
2016-09-20 17:37:20.868076 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [forward_busy_destination]=[UNDEF]
EXECUTE sofia/external/2505555555@456.456.456.456
set(forward_no_answer_enabled=)
2016-09-20 17:37:20.868076 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [forward_no_answer_enabled]=[UNDEF]
EXECUTE sofia/external/2505555555@456.456.456.456 set(forward_no_answer_
destination=)
2016-09-20 17:37:20.868076 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [forward_no_answer_destination]=[UNDEF]
EXECUTE sofia/external/2505555555@456.456.456.456 set(forward_user_not_
registered_enabled=)
2016-09-20 17:37:20.868076 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [forward_user_not_registered_enabled]=[UNDEF]
EXECUTE sofia/external/2505555555@456.456.456.456 set(forward_user_not_
registered_destination=)
2016-09-20 17:37:20.868076 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [forward_user_not_registered_destination]=[UNDEF]
EXECUTE sofia/external/2505555555@456.456.456.456 set(do_not_disturb=)
2016-09-20 17:37:20.868076 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [do_not_disturb]=[UNDEF]
EXECUTE sofia/external/2505555555@456.456.456.456 set(call_timeout=30)
2016-09-20 17:37:20.868076 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [call_timeout]=[30]
EXECUTE sofia/external/2505555555@456.456.456.456 set(missed_call_app=)
2016-09-20 17:37:20.888079 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [missed_call_app]=[UNDEF]
EXECUTE sofia/external/2505555555@456.456.456.456 set(missed_call_data=)
2016-09-20 17:37:20.888079 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [missed_call_data]=[UNDEF]
EXECUTE sofia/external/2505555555@456.456.456.456
export(origination_callee_id_name=2001)
2016-09-20 17:37:20.888079 [DEBUG] switch_channel.c:1296 EXPORT
(export_vars) [origination_callee_id_name]=[2001]
EXECUTE sofia/external/2505555555@456.456.456.456 set(RFC2822_DATE=Tue, 20
Sep 2016 17:37:20 -0700)
2016-09-20 17:37:20.888079 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [RFC2822_DATE]=[Tue, 20 Sep 2016 17:37:20 -0700]
EXECUTE sofia/external/2505555555@456.456.456.456
export(origination_callee_id_name=2001)
2016-09-20 17:37:20.888079 [DEBUG] switch_channel.c:1296 EXPORT
(export_vars) [origination_callee_id_name]=[2001]
EXECUTE sofia/external/2505555555@456.456.456.456 set(RFC2822_DATE=Tue, 20
Sep 2016 17:37:20 -0700)
2016-09-20 17:37:20.888079 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [RFC2822_DATE]=[Tue, 20 Sep 2016 17:37:20 -0700]
EXECUTE sofia/external/2505555555@456.456.456.456 hash(insert/sipa.test.com-
last_dial/2505555555/2001)
EXECUTE sofia/external/2505555555@456.456.456.456 hash(insert/sipa.test.com-
last_dial/2505555555/2001)
EXECUTE sofia/external/2505555555@456.456.456.456 eval(not_secure)
EXECUTE sofia/external/2505555555@456.456.456.456 eval(not_secure)
EXECUTE sofia/external/2505555555@456.456.456.456 limit(hash sipa.test.com 2001
 )
2016-09-20 17:37:20.888079 [DEBUG] switch_limit.c:126 incr called:
sipa.test.com_2001 max:-1, interval:0
2016-09-20 17:37:20.888079 [DEBUG] mod_hash.c:194 Usage for
sipa.test.com_2001 is now 1
EXECUTE sofia/external/2505555555@456.456.456.456
bind_digit_action(local,*1,exec:execute_extension,dx XML sipa.test.com,peer)
2016-09-20 17:37:20.888079 [INFO] switch_ivr_async.c:214 Digit parser
DPTOOLS: Setting realm to 'local'
2016-09-20 17:37:20.888079 [DEBUG] switch_ivr_async.c:323 Digit parser
DPTOOLS: binding *1/local/0 callback: 0x7fa72544ba00 data: 0x7fa6c40246d0
EXECUTE sofia/external/2505555555@456.456.456.456
bind_digit_action(local,*2,exec:record_session,/usr/
local/freeswitch/recordings/sipa.test.com/archive/2016/Sep/
20/8e70d2d8-7f93-11e6-a71d-79c835def150.wav,peer)
2016-09-20 17:37:20.888079 [DEBUG] switch_ivr_async.c:323 Digit parser
DPTOOLS: binding *2/local/0 callback: 0x7fa72544ba00 data: 0x7fa6c4024928
EXECUTE sofia/external/2505555555@456.456.456.456
bind_digit_action(local,*3,exec:execute_extension,cf XML sipa.test.com,peer)
2016-09-20 17:37:20.888079 [DEBUG] switch_ivr_async.c:323 Digit parser
DPTOOLS: binding *3/local/0 callback: 0x7fa72544ba00 data: 0x7fa6c4024ae0
EXECUTE sofia/external/2505555555@456.456.456.456
bind_digit_action(local,*4,exec:execute_extension,att_xfer XML sipa.test.com
,peer)
2016-09-20 17:37:20.888079 [DEBUG] switch_ivr_async.c:323 Digit parser
DPTOOLS: binding *4/local/0 callback: 0x7fa72544ba00 data: 0x7fa6c4024c50
EXECUTE sofia/external/2505555555@456.456.456.456
digit_action_set_realm(local)
EXECUTE sofia/external/2505555555@456.456.456.456
set(hangup_after_bridge=true)
2016-09-20 17:37:20.888079 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [hangup_after_bridge]=[true]
EXECUTE sofia/external/2505555555@456.456.456.456 set(continue_on_fail=true)
2016-09-20 17:37:20.888079 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [continue_on_fail]=[true]
EXECUTE sofia/external/2505555555@456.456.456.456 hash(insert/sipa.test.com-
call_return/2001/2505555555)
EXECUTE sofia/external/2505555555@456.456.456.456 hash(insert/sipa.test.com-
last_dial_ext/2001/8e70d2d8-7f93-11e6-a71d-79c835def150)
EXECUTE sofia/external/2505555555@456.456.456.456
set(called_party_call_group=)
2016-09-20 17:37:20.888079 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [called_party_call_group]=[UNDEF]
EXECUTE sofia/external/2505555555@456.456.456.456 hash(insert/sipa.test.com-
last_dial//8e70d2d8-7f93-11e6-a71d-79c835def150)
EXECUTE sofia/external/2505555555@456.456.456.456 set(api_hangup_hook=lua
app.lua hangup)
2016-09-20 17:37:20.888079 [DEBUG] mod_dptools.c:1519 SET sofia/external/
2505555555@456.456.456.456 [api_hangup_hook]=[lua app.lua hangup]
EXECUTE sofia/external/2505555555@456.456.456.456 bridge(user/
2001@sipa.test.com)
2016-09-20 17:37:20.888079 [DEBUG] switch_channel.c:1250 sofia/external/
2505555555@456.456.456.456 EXPORTING[export_vars] [dialed_extension]=[2001]
to event
2016-09-20 17:37:20.888079 [DEBUG] switch_channel.c:1250 sofia/external/
2505555555@456.456.456.456 EXPORTING[export_vars] [dialed_extension]=[2001]
to event
2016-09-20 17:37:20.888079 [DEBUG] switch_channel.c:1250 sofia/external/
2505555555@456.456.456.456 EXPORTING[export_vars]
[origination_callee_id_name]=[2001] to event
2016-09-20 17:37:20.888079 [DEBUG] switch_channel.c:1250 sofia/external/
2505555555@456.456.456.456 EXPORTING[export_vars]
[origination_callee_id_name]=[2001] to event
2016-09-20 17:37:20.888079 [DEBUG] switch_ivr_originate.c:2138 Parsing
global variables
2016-09-20 17:37:20.888079 [DEBUG] switch_channel.c:1250 sofia/external/
2505555555@456.456.456.456 EXPORTING[export_vars] [dialed_extension]=[2001]
to event
2016-09-20 17:37:20.888079 [DEBUG] switch_channel.c:1250 sofia/external/
2505555555@456.456.456.456 EXPORTING[export_vars] [dialed_extension]=[2001]
to event
2016-09-20 17:37:20.888079 [DEBUG] switch_channel.c:1250 sofia/external/
2505555555@456.456.456.456 EXPORTING[export_vars]
[origination_callee_id_name]=[2001] to event
2016-09-20 17:37:20.888079 [DEBUG] switch_channel.c:1250 sofia/external/
2505555555@456.456.456.456 EXPORTING[export_vars]
[origination_callee_id_name]=[2001] to event
2016-09-20 17:37:20.888079 [DEBUG] switch_ivr_originate.c:2138 Parsing
global variables
2016-09-20 17:37:20.888079 [NOTICE] switch_channel.c:1104 New Channel
sofia/internal/2001@72.143.224.138:20365 [8e7f1640-7f93-11e6-a766-
79c835def150]
2016-09-20 17:37:20.888079 [DEBUG] mod_sofia.c:4753 (sofia/internal/
2001@72.143.224.138:20365) State Change CS_NEW -> CS_INIT
2016-09-20 17:37:20.888079 [DEBUG] switch_core_state_machine.c:543
(sofia/internal/2001@72.143.224.138:20365) Running State Change CS_INIT
2016-09-20 17:37:20.888079 [DEBUG] switch_core_state_machine.c:586
(sofia/internal/2001@72.143.224.138:20365) State INIT
2016-09-20 17:37:20.888079 [DEBUG] mod_sofia.c:90 sofia/internal/
2001@72.143.224.138:20365 SOFIA INIT
2016-09-20 17:37:20.888079 [DEBUG] sofia_glue.c:1282 sofia/internal/
2001@72.143.224.138:20365 sending invite version: 1.7.0 git 7258a24
2016-09-13 18:17:51Z 64bit
Local SDP:
v=0
o=FreeSWITCH 1474397650 1474397651 IN IP4 123.123.123.123
s=FreeSWITCH
c=IN IP4 123.123.123.123
t=0 0
m=audio 20590 RTP/AVP 0 9 8 3 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:9 G722/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
a=sendrecv

2016-09-20 17:37:20.888079 [DEBUG] switch_core_state_machine.c:40
sofia/internal/2001@72.143.224.138:20365 Standard INIT
2016-09-20 17:37:20.888079 [DEBUG] switch_core_state_machine.c:48
(sofia/internal/2001@72.143.224.138:20365) State Change CS_INIT ->
CS_ROUTING
2016-09-20 17:37:20.888079 [DEBUG] switch_core_state_machine.c:586
(sofia/internal/2001@72.143.224.138:20365) State INIT going to sleep
2016-09-20 17:37:20.888079 [DEBUG] switch_core_state_machine.c:543
(sofia/internal/2001@72.143.224.138:20365) Running State Change CS_ROUTING
2016-09-20 17:37:20.888079 [DEBUG] switch_core_state_machine.c:602
(sofia/internal/2001@72.143.224.138:20365) State ROUTING
2016-09-20 17:37:20.888079 [DEBUG] mod_sofia.c:143 sofia/internal/
2001@72.143.224.138:20365 SOFIA ROUTING
2016-09-20 17:37:20.888079 [DEBUG] switch_ivr_originate.c:67
(sofia/internal/2001@72.143.224.138:20365) State Change CS_ROUTING ->
CS_CONSUME_MEDIA
2016-09-20 17:37:20.888079 [DEBUG] switch_core_state_machine.c:602
(sofia/internal/2001@72.143.224.138:20365) State ROUTING going to sleep
2016-09-20 17:37:20.888079 [DEBUG] switch_core_state_machine.c:543
(sofia/internal/2001@72.143.224.138:20365) Running State Change
CS_CONSUME_MEDIA
2016-09-20 17:37:20.888079 [DEBUG] switch_core_state_machine.c:621
(sofia/internal/2001@72.143.224.138:20365) State CONSUME_MEDIA
2016-09-20 17:37:20.888079 [DEBUG] switch_core_state_machine.c:621
(sofia/internal/2001@72.143.224.138:20365) State CONSUME_MEDIA going to
sleep
2016-09-20 17:37:20.888079 [DEBUG] sofia.c:6963 Channel sofia/internal/
2001@72.143.224.138:20365 entering state [calling][0]
2016-09-20 17:37:22.228117 [DEBUG] sofia.c:6963 Channel sofia/internal/
2001@72.143.224.138:20365 entering state [proceeding][180]
2016-09-20 17:37:22.228117 [NOTICE] sofia.c:7071 Ring-Ready sofia/internal/
2001@72.143.224.138:20365!
2016-09-20 17:37:22.228117 [DEBUG] switch_channel.c:3343 (sofia/internal/
2001@72.143.224.138:20365) Callstate Change DOWN -> RINGING
2016-09-20 17:37:22.248125 [NOTICE] mod_sofia.c:2216 Ring-Ready
sofia/external/2505555555@456.456.456.456!
2016-09-20 17:37:22.248125 [DEBUG] sofia.c:6963 Channel sofia/external/
2505555555@456.456.456.456 entering state [early][180]
2016-09-20 17:37:22.248125 [NOTICE] switch_ivr_originate.c:525 Ring Ready
sofia/external/2505555555@456.456.456.456!
2016-09-20 17:37:23.828155 [DEBUG] sofia.c:6963 Channel sofia/internal/
2001@72.143.224.138:20365 entering state [completing][200]
2016-09-20 17:37:23.828155 [DEBUG] sofia.c:6973 Remote SDP:
v=0
o=Zoiper 0 1 IN IP4 25.171.247.182
s=Zoiper
c=IN IP4 25.171.247.182
t=0 0
m=audio 54200 RTP/AVP 0 3 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:3 GSM/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16

2016-09-20 17:37:23.828155 [DEBUG] sofia.c:6963 Channel sofia/internal/
2001@72.143.224.138:20365 entering state [ready][200]
2016-09-20 17:37:23.848111 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2016-09-20 17:37:23.848111 [DEBUG] switch_core_media.c:4336 Audio Codec
Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2016-09-20 17:37:23.848111 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2016-09-20 17:37:23.848111 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2016-09-20 17:37:23.848111 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2016-09-20 17:37:23.848111 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
2016-09-20 17:37:23.848111 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [GSM:3:8000:20:13200:1]/[G722:9:8000:20:64000:1]
2016-09-20 17:37:23.848111 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
2016-09-20 17:37:23.848111 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [GSM:3:8000:20:13200:1]/[GSM:3:8000:20:13200:1]
2016-09-20 17:37:23.848111 [DEBUG] switch_core_media.c:4336 Audio Codec
Compare [GSM:3:8000:20:13200:1] ++++ is saved as a match
2016-09-20 17:37:23.848111 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2016-09-20 17:37:23.848111 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2016-09-20 17:37:23.848111 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2016-09-20 17:37:23.848111 [DEBUG] switch_core_media.c:4336 Audio Codec
Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2016-09-20 17:37:23.848111 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [PCMA:8:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2016-09-20 17:37:23.848111 [DEBUG] switch_core_media.c:4197 Set
telephone-event payload to 101@8000
2016-09-20 17:37:23.848111 [DEBUG] switch_core_media.c:3017 Set Codec
sofia/internal/2001@72.143.224.138:20365 PCMU/8000 20 ms 160 samples 64000
bits 1 channels
2016-09-20 17:37:23.848111 [DEBUG] switch_core_codec.c:111 sofia/internal/
2001@72.143.224.138:20365 Original read codec set to PCMU:0
2016-09-20 17:37:23.848111 [DEBUG] switch_core_media.c:4542 Set
telephone-event payload to 101@8000
2016-09-20 17:37:23.848111 [DEBUG] switch_core_media.c:4601 sofia/internal/
2001@72.143.224.138:20365 Set 2833 dtmf send payload to 101 recv payload to
101
2016-09-20 17:37:23.848111 [DEBUG] switch_core_media.c:6438 AUDIO RTP
[sofia/internal/2001@72.143.224.138:20365] 123.123.123.123 port 20590 ->
25.171.247.182 port 54200 codec: 0 ms: 20
2016-09-20 17:37:23.848111 [DEBUG] switch_rtp.c:3838 Starting timer [soft]
160 bytes per 20ms
2016-09-20 17:37:23.848111 [DEBUG] switch_core_media.c:6737 sofia/internal/
2001@72.143.224.138:20365 Set 2833 dtmf send payload to 101
2016-09-20 17:37:23.848111 [DEBUG] switch_core_media.c:6744 sofia/internal/
2001@72.143.224.138:20365 Set 2833 dtmf receive payload to 101
2016-09-20 17:37:23.848111 [DEBUG] switch_core_media.c:6767 sofia/internal/
2001@72.143.224.138:20365 Set rtp dtmf delay to 40
2016-09-20 17:37:23.848111 [NOTICE] sofia.c:8007 Channel [sofia/internal/
2001@72.143.224.138:20365] has been answered
2016-09-20 17:37:23.848111 [DEBUG] switch_core_media.c:6438 AUDIO RTP
[sofia/external/2505555555@456.456.456.456] 123.123.123.123 port 30642 ->
456.456.456.456 port 19772 codec: 0 ms: 20
2016-09-20 17:37:23.848111 [DEBUG] switch_rtp.c:3838 Starting timer [soft]
160 bytes per 20ms
2016-09-20 17:37:23.848111 [DEBUG] switch_channel.c:3770 (sofia/internal/
2001@72.143.224.138:20365) Callstate Change RINGING -> ACTIVE
2016-09-20 17:37:23.848111 [DEBUG] switch_core_media.c:6737 sofia/external/
2505555555@456.456.456.456 Set 2833 dtmf send payload to 101
2016-09-20 17:37:23.848111 [DEBUG] switch_core_media.c:6744 sofia/external/
2505555555@456.456.456.456 Set 2833 dtmf receive payload to 101
2016-09-20 17:37:23.848111 [DEBUG] switch_core_media.c:6767 sofia/external/
2505555555@456.456.456.456 Set rtp dtmf delay to 40
2016-09-20 17:37:23.848111 [DEBUG] mod_sofia.c:822 Local SDP sofia/external/
2505555555@456.456.456.456:
v=0
o=FreeSWITCH 1474387601 1474387602 IN IP4 123.123.123.123
s=FreeSWITCH
c=IN IP4 123.123.123.123
t=0 0
m=audio 30642 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

2016-09-20 17:37:23.848111 [NOTICE] switch_ivr_originate.c:3628 Channel
[sofia/external/2505555555@456.456.456.456] has been answered
2016-09-20 17:37:23.848111 [DEBUG] switch_channel.c:3770 (sofia/external/
2505555555@456.456.456.456) Callstate Change RINGING -> ACTIVE
2016-09-20 17:37:23.848111 [DEBUG] sofia.c:6963 Channel sofia/external/
2505555555@456.456.456.456 entering state [completed][200]
2016-09-20 17:37:23.848111 [DEBUG] switch_ivr_originate.c:3686 Originate
Resulted in Success: [sofia/internal/2001@72.143.224.138:20365]
2016-09-20 17:37:23.848111 [DEBUG] switch_ivr_originate.c:3686 Originate
Resulted in Success: [sofia/internal/2001@72.143.224.138:20365]
2016-09-20 17:37:23.848111 [DEBUG] switch_ivr_bridge.c:1599 (sofia/internal/
2001@72.143.224.138:20365) State Change CS_CONSUME_MEDIA ->
CS_EXCHANGE_MEDIA
2016-09-20 17:37:23.848111 [DEBUG] switch_core_state_machine.c:543
(sofia/internal/2001@72.143.224.138:20365) Running State Change
CS_EXCHANGE_MEDIA
2016-09-20 17:37:23.848111 [DEBUG] switch_core_state_machine.c:612
(sofia/internal/2001@72.143.224.138:20365) State EXCHANGE_MEDIA
2016-09-20 17:37:23.848111 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA
2016-09-20 17:37:23.848111 [DEBUG] sofia.c:6963 Channel sofia/external/
2505555555@456.456.456.456 entering state [ready][200]
2016-09-20 17:37:24.028124 [DEBUG] switch_rtp.c:6739 Correct audio ip/port
confirmed.
2016-09-20 17:37:24.128112 [INFO] switch_rtp.c:6701 Auto Changing audio
port from 25.171.247.182:54200 to 72.143.224.138:20373
2016-09-20 17:37:26.348133 [DEBUG] switch_rtp.c:6962 RTP RECV DTMF 8:960
2016-09-20 17:37:26.348133 [INFO] switch_channel.c:515 RECV DTMF 8:960
2016-09-20 17:37:26.348133 [DEBUG] mod_dptools.c:132 sofia/internal/
2001@72.143.224.138:20365 Digit NOT match binding [8]
2016-09-20 17:37:26.348133 [INFO] switch_channel.c:515 RECV DTMF 8:2000
2016-09-20 17:37:26.348133 [DEBUG] switch_channel.c:611 sofia/internal/
2001@72.143.224.138:20365 Queue dtmf
digit=8 ms=250 samples=2000
2016-09-20 17:37:26.348133 [DEBUG] switch_rtp.c:4943 Send start packet for
[8] ts=2079523031 dur=160/160/2000 seq=62866 lw=2079523031
2016-09-20 17:37:26.368123 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079523031 dur=320/320/2000 seq=62867 lw=2079523191
2016-09-20 17:37:26.388127 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079523031 dur=480/480/2000 seq=62868 lw=2079523351
2016-09-20 17:37:26.388127 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079523031 dur=640/640/2000 seq=62869 lw=2079523511
2016-09-20 17:37:26.388127 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079523031 dur=800/800/2000 seq=62870 lw=2079523671
2016-09-20 17:37:26.388127 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079523031 dur=960/960/2000 seq=62871 lw=2079523831
2016-09-20 17:37:26.428078 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079523031 dur=1120/1120/2000 seq=62872 lw=2079523991
2016-09-20 17:37:26.448180 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079523031 dur=1280/1280/2000 seq=62873 lw=2079524151
2016-09-20 17:37:26.448180 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079523031 dur=1440/1440/2000 seq=62874 lw=2079524311
2016-09-20 17:37:26.488089 [DEBUG] switch_rtp.c:6962 RTP RECV DTMF 8:960
2016-09-20 17:37:26.488089 [INFO] switch_channel.c:515 RECV DTMF 8:960
2016-09-20 17:37:26.488089 [DEBUG] mod_dptools.c:132 sofia/internal/
2001@72.143.224.138:20365 Digit NOT match binding [8]
2016-09-20 17:37:26.488089 [INFO] switch_channel.c:515 RECV DTMF 8:2000
2016-09-20 17:37:26.488089 [DEBUG] switch_channel.c:611 sofia/internal/
2001@72.143.224.138:20365 Queue dtmf
digit=8 ms=250 samples=2000
2016-09-20 17:37:26.488089 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079523031 dur=1600/1600/2000 seq=62875 lw=2079524471
2016-09-20 17:37:26.508075 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079523031 dur=1760/1760/2000 seq=62876 lw=2079524631
2016-09-20 17:37:26.508075 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079523031 dur=1920/1920/2000 seq=62877 lw=2079524791
2016-09-20 17:37:26.528109 [DEBUG] switch_rtp.c:4842 Send end packet for
[8] ts=2079523031 dur=2080/2080/2000 seq=62878 lw=2079524791
2016-09-20 17:37:26.528109 [DEBUG] switch_rtp.c:4842 Send end packet for
[8] ts=2079523031 dur=2080/2080/2000 seq=62879 lw=2079524791
2016-09-20 17:37:26.528109 [DEBUG] switch_rtp.c:4842 Send end packet for
[8] ts=2079523031 dur=2080/2080/2000 seq=62880 lw=2079524791
2016-09-20 17:37:26.528109 [DEBUG] switch_rtp.c:4795 Queue digit delay of
40ms
2016-09-20 17:37:26.568142 [DEBUG] switch_rtp.c:4943 Send start packet for
[8] ts=2079526071 dur=160/160/2000 seq=62883 lw=2079526071
2016-09-20 17:37:26.588110 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079526071 dur=320/320/2000 seq=62884 lw=2079526231
2016-09-20 17:37:26.588110 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079526071 dur=480/480/2000 seq=62885 lw=2079526391
2016-09-20 17:37:26.588110 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079526071 dur=640/640/2000 seq=62886 lw=2079526551
2016-09-20 17:37:26.628074 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079526071 dur=800/800/2000 seq=62887 lw=2079526711
2016-09-20 17:37:26.628074 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079526071 dur=960/960/2000 seq=62888 lw=2079526871
2016-09-20 17:37:26.648076 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079526071 dur=1120/1120/2000 seq=62889 lw=2079527031
2016-09-20 17:37:26.668076 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079526071 dur=1280/1280/2000 seq=62890 lw=2079527191
2016-09-20 17:37:26.688128 [DEBUG] switch_rtp.c:6962 RTP RECV DTMF 8:960
2016-09-20 17:37:26.688128 [INFO] switch_channel.c:515 RECV DTMF 8:960
2016-09-20 17:37:26.688128 [DEBUG] mod_dptools.c:132 sofia/internal/
2001@72.143.224.138:20365 Digit NOT match binding [8]
2016-09-20 17:37:26.688128 [INFO] switch_channel.c:515 RECV DTMF 8:2000
2016-09-20 17:37:26.688128 [DEBUG] switch_channel.c:611 sofia/internal/
2001@72.143.224.138:20365 Queue dtmf
digit=8 ms=250 samples=2000
2016-09-20 17:37:26.688128 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079526071 dur=1440/1440/2000 seq=62891 lw=2079527351
2016-09-20 17:37:26.688128 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079526071 dur=1600/1600/2000 seq=62892 lw=2079527511
2016-09-20 17:37:26.728126 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079526071 dur=1760/1760/2000 seq=62893 lw=2079527671
2016-09-20 17:37:26.728126 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079526071 dur=1920/1920/2000 seq=62894 lw=2079527831
2016-09-20 17:37:26.728126 [DEBUG] switch_rtp.c:4842 Send end packet for
[8] ts=2079526071 dur=2080/2080/2000 seq=62895 lw=2079527831
2016-09-20 17:37:26.728126 [DEBUG] switch_rtp.c:4842 Send end packet for
[8] ts=2079526071 dur=2080/2080/2000 seq=62896 lw=2079527831
2016-09-20 17:37:26.728126 [DEBUG] switch_rtp.c:4842 Send end packet for
[8] ts=2079526071 dur=2080/2080/2000 seq=62897 lw=2079527831
2016-09-20 17:37:26.728126 [DEBUG] switch_rtp.c:4795 Queue digit delay of
40ms
2016-09-20 17:37:26.828141 [DEBUG] switch_rtp.c:6962 RTP RECV DTMF 8:960
2016-09-20 17:37:26.828141 [INFO] switch_channel.c:515 RECV DTMF 8:960
2016-09-20 17:37:26.828141 [DEBUG] mod_dptools.c:132 sofia/internal/
2001@72.143.224.138:20365 Digit NOT match binding [8]
2016-09-20 17:37:26.828141 [INFO] switch_channel.c:515 RECV DTMF 8:2000
2016-09-20 17:37:26.828141 [DEBUG] switch_channel.c:611 sofia/internal/
2001@72.143.224.138:20365 Queue dtmf
digit=8 ms=250 samples=2000
2016-09-20 17:37:26.888119 [DEBUG] switch_rtp.c:4943 Send start packet for
[8] ts=2079528951 dur=160/160/2000 seq=62900 lw=2079528951
2016-09-20 17:37:26.888119 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079528951 dur=320/320/2000 seq=62901 lw=2079529111
2016-09-20 17:37:26.928075 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079528951 dur=480/480/2000 seq=62902 lw=2079529271
2016-09-20 17:37:26.928075 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079528951 dur=640/640/2000 seq=62903 lw=2079529431
2016-09-20 17:37:26.948077 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079528951 dur=800/800/2000 seq=62904 lw=2079529591
2016-09-20 17:37:26.948077 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079528951 dur=960/960/2000 seq=62905 lw=2079529751
2016-09-20 17:37:26.968075 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079528951 dur=1120/1120/2000 seq=62906 lw=2079529911
2016-09-20 17:37:26.988075 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079528951 dur=1280/1280/2000 seq=62907 lw=2079530071
2016-09-20 17:37:27.008076 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079528951 dur=1440/1440/2000 seq=62908 lw=2079530231
2016-09-20 17:37:27.028074 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079528951 dur=1600/1600/2000 seq=62909 lw=2079530391
2016-09-20 17:37:27.028074 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079528951 dur=1760/1760/2000 seq=62910 lw=2079530551
2016-09-20 17:37:27.048076 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079528951 dur=1920/1920/2000 seq=62911 lw=2079530711
2016-09-20 17:37:27.048076 [DEBUG] switch_rtp.c:4842 Send end packet for
[8] ts=2079528951 dur=2080/2080/2000 seq=62912 lw=2079530711
2016-09-20 17:37:27.048076 [DEBUG] switch_rtp.c:4842 Send end packet for
[8] ts=2079528951 dur=2080/2080/2000 seq=62913 lw=2079530711
2016-09-20 17:37:27.048076 [DEBUG] switch_rtp.c:4842 Send end packet for
[8] ts=2079528951 dur=2080/2080/2000 seq=62914 lw=2079530711
2016-09-20 17:37:27.048076 [DEBUG] switch_rtp.c:4795 Queue digit delay of
40ms
2016-09-20 17:37:27.088092 [DEBUG] switch_rtp.c:4943 Send start packet for
[8] ts=2079530551 dur=160/160/2000 seq=62917 lw=2079530551
2016-09-20 17:37:27.108125 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079530551 dur=320/320/2000 seq=62918 lw=2079530711
2016-09-20 17:37:27.128106 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079530551 dur=480/480/2000 seq=62919 lw=2079530871
2016-09-20 17:37:27.128106 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079530551 dur=640/640/2000 seq=62920 lw=2079531031
2016-09-20 17:37:27.128106 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079530551 dur=800/800/2000 seq=62921 lw=2079531191
2016-09-20 17:37:27.128106 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079530551 dur=960/960/2000 seq=62922 lw=2079531351
2016-09-20 17:37:27.168076 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079530551 dur=1120/1120/2000 seq=62923 lw=2079531511
2016-09-20 17:37:27.188127 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079530551 dur=1280/1280/2000 seq=62924 lw=2079531671
2016-09-20 17:37:27.188127 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079530551 dur=1440/1440/2000 seq=62925 lw=2079531831
2016-09-20 17:37:27.228074 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079530551 dur=1600/1600/2000 seq=62926 lw=2079531991
2016-09-20 17:37:27.248076 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079530551 dur=1760/1760/2000 seq=62927 lw=2079532151
2016-09-20 17:37:27.248076 [DEBUG] switch_rtp.c:4842 Send middle packet for
[8] ts=2079530551 dur=1920/1920/2000 seq=62928 lw=2079532311
2016-09-20 17:37:27.268080 [DEBUG] switch_rtp.c:4842 Send end packet for
[8] ts=2079530551 dur=2080/2080/2000 seq=62929 lw=2079532311
2016-09-20 17:37:27.268080 [DEBUG] switch_rtp.c:4842 Send end packet for
[8] ts=2079530551 dur=2080/2080/2000 seq=62930 lw=2079532311
2016-09-20 17:37:27.268080 [DEBUG] switch_rtp.c:4842 Send end packet for
[8] ts=2079530551 dur=2080/2080/2000 seq=62931 lw=2079532311
2016-09-20 17:37:27.268080 [DEBUG] switch_rtp.c:4795 Queue digit delay of
40ms
freeswitch@fusion>

SERVER B

freeswitch@fusion> sofia recover
Recovered 2 call(s)

2016-09-20 17:37:35.289629 [NOTICE] switch_channel.c:1104 New Channel
sofia/external/2505555555@456.456.456.456 [8e70d2d8-7f93-11e6-a71d-
79c835def150]
2016-09-20 17:37:35.289629 [NOTICE] switch_channel.c:1102 Rename Channel
sofia/external/2505555555@456.456.456.456->sofia/external/2505555555@456.456.456.456
[8e70d2d8-7f93-11e6-a71d-79c835def150]
2016-09-20 17:37:35.289629 [DEBUG] switch_core_media.c:3017 Set Codec
sofia/external/2505555555@456.456.456.456 PCMU/8000 20 ms 160 samples 64000
bits 1 channels
2016-09-20 17:37:35.289629 [DEBUG] switch_core_codec.c:111 sofia/external/
2505555555@456.456.456.456 Original read codec set to PCMU:0
2016-09-20 17:37:35.289629 [DEBUG] switch_core_media.c:6438 AUDIO RTP
[sofia/external/2505555555@456.456.456.456] 123.123.123.123 port 30642 ->
456.456.456.456 port 19772 codec: 0 ms: 20
2016-09-20 17:37:35.289629 [DEBUG] switch_rtp.c:3838 Starting timer [soft]
160 bytes per 20ms
2016-09-20 17:37:35.289629 [DEBUG] switch_core_media.c:6737 sofia/external/
2505555555@456.456.456.456 Set 2833 dtmf send payload to 101
2016-09-20 17:37:35.289629 [DEBUG] switch_core_media.c:6744 sofia/external/
2505555555@456.456.456.456 Set 2833 dtmf receive payload to 101
2016-09-20 17:37:35.289629 [DEBUG] switch_core_media.c:6767 sofia/external/
2505555555@456.456.456.456 Set rtp dtmf delay to 40
2016-09-20 17:37:35.289629 [DEBUG] switch_core_media.c:6773 Set comfort
noise payload to 13
2016-09-20 17:37:35.289629 [DEBUG] switch_core_sqldb.c:3036 (sofia/external/
2505555555@456.456.456.456) State Change CS_NEW -> CS_INIT
2016-09-20 17:37:35.289629 [NOTICE] switch_core_sqldb.c:3037 Resurrecting
fallen channel sofia/external/2505555555@456.456.456.456
2016-09-20 17:37:35.289629 [DEBUG] switch_core_state_machine.c:543
(sofia/external/2505555555@456.456.456.456) Running State Change CS_INIT
2016-09-20 17:37:35.289629 [DEBUG] switch_channel.c:2251 (sofia/external/
2505555555@456.456.456.456) Callstate Change DOWN -> ACTIVE
2016-09-20 17:37:35.289629 [DEBUG] switch_core_state_machine.c:586
(sofia/external/2505555555@456.456.456.456) State INIT
2016-09-20 17:37:35.289629 [DEBUG] mod_sofia.c:90 sofia/external/2505555555
@456.456.456.456 SOFIA INIT
2016-09-20 17:37:35.289629 [DEBUG] sofia_glue.c:1282 sofia/external/
2505555555@456.456.456.456 sending invite version: 1.7.0 git 7258a24
2016-09-13 18:17:51Z 64bit
Local SDP:
v=0
o=FreeSWITCH 1474387613 1474387615 IN IP4 123.123.123.123
s=FreeSWITCH
c=IN IP4 123.123.123.123
t=0 0
m=audio 30642 RTP/AVP 0 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/0
a=fmtp:101 0-16
a=rtpmap:13 CN/0
a=ptime:20
a=sendrecv

2016-09-20 17:37:35.289629 [DEBUG] switch_core_state_machine.c:40
sofia/external/2505555555@456.456.456.456 Standard INIT
2016-09-20 17:37:35.289629 [DEBUG] switch_core_state_machine.c:43
(sofia/external/2505555555@456.456.456.456) State Change CS_INIT -> CS_RESET
send 1123 bytes to udp/[456.456.456.456]:5060 at 17:37:35.295527:
   ------------------------------------------------------------------------
   INVITE sip:2505555555@456.456.456.456:5060 SIP/2.0
   Via: SIP/2.0/UDP 123.123.123.123:5080;rport;branch=z9hG4bKr2jctgUFrDmpK
   Route: <sip:2505555555@456.456.456.456:5060;transport=udp>
   Max-Forwards: 69
   From: <sip:7786962265@123.123.123.123:5080>;tag=28mBjg3pvH3SK
   To: "SOKAMLOOPS BC " <sip:2505555555@456.456.456.456>;tag=as755f2144
   Call-ID: 3a3825c20a395c2f02a629bd22ef969c@456.456.456.456:5060
   CSeq: 96873063 INVITE
   Contact: <sip:2505555555@123.123.123.123:5080>
   User-Agent: FreeSWITCH
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
REGISTER, REFER, NOTIFY
   Supported: timer, path, replaces
   Allow-Events: talk, hold, conference, refer
   Content-Type: application/sdp
e   Content-Disposition: session
   Content-Length: 244
   X-FS-Support: update_display,send_info
   Remote-Party-ID: "7786962265" <sip:7786962265@456.456.456.
456>;party=calling;screen=yes;privacy=off

   v=0
   o=FreeSWITCH 1474387613 1474387615 IN IP4 123.123.123.123
   s=FreeSWITCH
   c=IN IP4 123.123.123.123
   t=0 0
   m=audio 30642 RTP/AVP 0 101 13
   a=rtpmap:0 PCMU/8000
   a=rtpmap:101 telephone-event/0
   a=fmtp:101 0-16
   a=rtpmap:13 CN/0
   a=ptime:20
   ------------------------------------------------------------------------
2016-09-20 17:37:35.289629 [DEBUG] switch_core_state_machine.c:586
(sofia/external/2505555555@456.456.456.456) State INIT going to sleep
2016-09-20 17:37:35.289629 [DEBUG] switch_core_state_machine.c:543
(sofia/external/2505555555@456.456.456.456) Running State Change CS_RESET
2016-09-20 17:37:35.289629 [DEBUG] sofia.c:6963 Channel sofia/external/
2505555555@456.456.456.456 entering state [calling][0]
2016-09-20 17:37:35.289629 [DEBUG] switch_core_state_machine.c:605
(sofia/external/2505555555@456.456.456.456) State RESET
2016-09-20 17:37:35.289629 [DEBUG] mod_sofia.c:161 sofia/external/2505555555
@456.456.456.456 SOFIA RESET
2016-09-20 17:37:35.289629 [DEBUG] switch_core_state_machine.c:188
sofia/external/2505555555@456.456.456.456 Standard RESET
2016-09-20 17:37:35.289629 [DEBUG] switch_core_state_machine.c:605
(sofia/external/2505555555@456.456.456.456) State RESET going to sleep
2016-09-20 17:37:35.289629 [NOTICE] switch_channel.c:1104 New Channel
sofia/internal/2001@72.143.224.138:20365 [8e7f1640-7f93-11e6-a766-
79c835def150]
2016-09-20 17:37:35.289629 [NOTICE] switch_channel.c:1102 Rename Channel
sofia/internal/2001@72.143.224.138:20365->sofia/internal/
2001@72.143.224.138:20365 [8e7f1640-7f93-11e6-a766-79c835def150]
2016-09-20 17:37:35.289629 [DEBUG] switch_core_media.c:3017 Set Codec
sofia/internal/2001@72.143.224.138:20365 PCMU/8000 20 ms 160 samples 64000
bits 1 channels
2016-09-20 17:37:35.289629 [DEBUG] switch_core_codec.c:111 sofia/internal/
2001@72.143.224.138:20365 Original read codec set to PCMU:0
2016-09-20 17:37:35.289629 [DEBUG] switch_core_media.c:6438 AUDIO RTP
[sofia/internal/2001@72.143.224.138:20365] 123.123.123.123 port 20590 ->
25.171.247.182 port 54200 codec: 0 ms: 20
2016-09-20 17:37:35.289629 [DEBUG] switch_rtp.c:3838 Starting timer [soft]
160 bytes per 20ms
2016-09-20 17:37:35.289629 [DEBUG] switch_core_media.c:6737 sofia/internal/
2001@72.143.224.138:20365 Set 2833 dtmf send payload to 101
2016-09-20 17:37:35.289629 [DEBUG] switch_core_media.c:6744 sofia/internal/
2001@72.143.224.138:20365 Set 2833 dtmf receive payload to 101
2016-09-20 17:37:35.289629 [DEBUG] switch_core_media.c:6767 sofia/internal/
2001@72.143.224.138:20365 Set rtp dtmf delay to 40
2016-09-20 17:37:35.289629 [DEBUG] switch_core_media.c:6773 Set comfort
noise payload to 13
2016-09-20 17:37:35.289629 [DEBUG] switch_core_sqldb.c:3036 (sofia/internal/
2001@72.143.224.138:20365) State Change CS_NEW -> CS_INIT
2016-09-20 17:37:35.289629 [NOTICE] switch_core_sqldb.c:3037 Resurrecting
fallen channel sofia/internal/2001@72.143.224.138:20365
2016-09-20 17:37:35.289629 [DEBUG] switch_core_state_machine.c:543
(sofia/internal/2001@72.143.224.138:20365) Running State Change CS_INIT
2016-09-20 17:37:35.289629 [DEBUG] switch_core_state_machine.c:586
(sofia/internal/2001@72.143.224.138:20365) State INIT
2016-09-20 17:37:35.289629 [DEBUG] mod_sofia.c:90 sofia/internal/
2001@72.143.224.138:20365 SOFIA INIT
2016-09-20 17:37:35.289629 [DEBUG] sofia_glue.c:1282 sofia/internal/
2001@72.143.224.138:20365 sending invite version: 1.7.0 git 7258a24
2016-09-13 18:17:51Z 64bit
Local SDP:
v=0
o=FreeSWITCH 1474397665 1474397667 IN IP4 123.123.123.123
s=FreeSWITCH
c=IN IP4 123.123.123.123
t=0 0
m=audio 20590 RTP/AVP 0 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/0
a=fmtp:101 0-16
a=rtpmap:13 CN/0
a=ptime:20
a=sendrecv

2016-09-20 17:37:35.289629 [DEBUG] switch_core_state_machine.c:40
sofia/internal/2001@72.143.224.138:20365 Standard INIT
2016-09-20 17:37:35.289629 [DEBUG] switch_core_state_machine.c:43
(sofia/internal/2001@72.143.224.138:20365) State Change CS_INIT -> CS_RESET
send 1323 bytes to udp/[72.143.224.138]:20365 at 17:37:35.299037:
   ------------------------------------------------------------------------
   INVITE sip:2001@72.143.224.138:20365;transport=UDP SIP/2.0
   Via: SIP/2.0/UDP 123.123.123.123;rport;branch=z9hG4bK0DU6aXj2FvHBp
   Via: SIP/2.0/UDP 123.123.123.123;rport=5060;branch=z9hG4bKvXKtj06r89vca
   Max-Forwards: 68
   From: "SOKAMLOOPS BC " <sip:2505555555@sipa.test.com>;tag=vDHFU74UXyNmS
   To: <sip:2001@72.143.224.138:20365;transport=UDP;rinstance=
d85e769961280fbc>;tag=14496d0a
   Call-ID: 65dd6ddc-fa36-1234-b68d-1803730b83c5
   CSeq: 96873063 INVITE
   Contact: <sip:2001@123.123.123.123:5060>
   User-Agent: FreeSWITCH
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, path, replaces
   Allow-Events: talk, hold, conference, presence, as-feature-event,
dialog, line-seize, call-info, sla, include-session-description,
presence.winfo, message-summary, refer
   Content-Type: application/sdp
   Content-Disposition: session
   Content-Length: 244
   X-FS-Support: update_display,send_info
   Remote-Party-ID: "SOKAMLOOPS BC " <sip:2505555555@sipa.test.com>
;party=calling;screen=yes;privacy=off

   v=0
   o=FreeSWITCH 1474397665 1474397667 IN IP4 123.123.123.123
   s=FreeSWITCH
   c=IN IP4 123.123.123.123
   t=0 0
   m=audio 20590 RTP/AVP 0 101 13
   a=rtpmap:0 PCMU/8000
   a=rtpmap:101 telephone-event/0
   a=fmtp:101 0-16
   a=rtpmap:13 CN/0
   a=ptime:20
   ------------------------------------------------------------------------
2016-09-20 17:37:35.289629 [DEBUG] switch_core_state_machine.c:586
(sofia/internal/2001@72.143.224.138:20365) State INIT going to sleep
2016-09-20 17:37:35.289629 [DEBUG] switch_core_state_machine.c:543
(sofia/internal/2001@72.143.224.138:20365) Running State Change CS_RESET
2016-09-20 17:37:35.289629 [DEBUG] sofia.c:6963 Channel sofia/internal/
2001@72.143.224.138:20365 entering state [calling][0]
2016-09-20 17:37:35.289629 [DEBUG] switch_core_state_machine.c:605
(sofia/internal/2001@72.143.224.138:20365) State RESET
2016-09-20 17:37:35.289629 [DEBUG] mod_sofia.c:161 sofia/internal/
2001@72.143.224.138:20365 SOFIA RESET
2016-09-20 17:37:35.289629 [DEBUG] switch_core_state_machine.c:188
sofia/internal/2001@72.143.224.138:20365 Standard RESET
2016-09-20 17:37:35.289629 [DEBUG] switch_core_state_machine.c:605
(sofia/internal/2001@72.143.224.138:20365) State RESET going to sleep
recv 520 bytes from udp/[456.456.456.456]:5060 at 17:37:35.303679:
   ------------------------------------------------------------------------
   SIP/2.0 481 Call/Transaction Does Not Exist
   Via: SIP/2.0/UDP 123.123.123.123:5080;branch=
z9hG4bKr2jctgUFrDmpK;received=123.123.123.123;rport=5080
   From: <sip:7786962265@123.123.123.123:5080>;tag=28mBjg3pvH3SK
   To: "SOKAMLOOPS BC " <sip:2505555555@456.456.456.456>;tag=as755f2144
   Call-ID: 3a3825c20a395c2f02a629bd22ef969c@456.456.456.456:5060
   CSeq: 96873063 INVITE
   Server: Itelnetworks
   Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY,
INFO, PUBLISH, MESSAGE
   Supported: replaces
   Content-Length: 0

   ------------------------------------------------------------------------
send 430 bytes to udp/[456.456.456.456]:5060 at 17:37:35.303739:
   ------------------------------------------------------------------------
   ACK sip:2505555555@456.456.456.456:5060 SIP/2.0
   Via: SIP/2.0/UDP 123.123.123.123:5080;rport;branch=z9hG4bKr2jctgUFrDmpK
   Route: <sip:2505555555@456.456.456.456:5060;transport=udp>
   Max-Forwards: 69
   From: <sip:7786962265@123.123.123.123:5080>;tag=28mBjg3pvH3SK
   To: "SOKAMLOOPS BC " <sip:2505555555@456.456.456.456>;tag=as755f2144
   Call-ID: 3a3825c20a395c2f02a629bd22ef969c@456.456.456.456:5060
   CSeq: 96873063 ACK
   Content-Length: 0

   ------------------------------------------------------------------------
2016-09-20 17:37:35.289629 [DEBUG] sofia.c:6963 Channel sofia/external/
2505555555@456.456.456.456 entering state [terminated][481]
2016-09-20 17:37:35.289629 [NOTICE] sofia.c:8062 Hangup sofia/external/
2505555555@456.456.456.456 [CS_RESET] [NORMAL_TEMPORARY_FAILURE]
2016-09-20 17:37:35.289629 [DEBUG] switch_core_state_machine.c:543
(sofia/external/2505555555@456.456.456.456) Running State Change CS_HANGUP
2016-09-20 17:37:35.289629 [DEBUG] switch_core_state_machine.c:809
(sofia/external/2505555555@456.456.456.456) Callstate Change ACTIVE ->
HANGUP
2016-09-20 17:37:35.289629 [DEBUG] switch_core_state_machine.c:811
(sofia/external/2505555555@456.456.456.456) State HANGUP
2016-09-20 17:37:35.289629 [DEBUG] mod_sofia.c:438 Channel sofia/external/
2505555555@456.456.456.456 hanging up, cause: NORMAL_TEMPORARY_FAILURE
2016-09-20 17:37:35.289629 [DEBUG] switch_core_state_machine.c:60
sofia/external/2505555555@456.456.456.456 Standard HANGUP, cause:
NORMAL_TEMPORARY_FAILURE
2016-09-20 17:37:35.289629 [DEBUG] switch_core_state_machine.c:811
(sofia/external/2505555555@456.456.456.456) State HANGUP going to sleep
2016-09-20 17:37:35.289629 [DEBUG] switch_core_state_machine.c:742 Hangup
Command with no Session lua(app.lua hangup):

2016-09-20 17:37:35.289629 [DEBUG] switch_core_state_machine.c:578
(sofia/external/2505555555@456.456.456.456) State Change CS_HANGUP ->
CS_REPORTING
2016-09-20 17:37:35.289629 [DEBUG] switch_core_state_machine.c:543
(sofia/external/2505555555@456.456.456.456) Running State Change
CS_REPORTING
2016-09-20 17:37:35.289629 [DEBUG] switch_core_state_machine.c:897
(sofia/external/2505555555@456.456.456.456) State REPORTING
2016-09-20 17:37:35.329553 [DEBUG] switch_core_state_machine.c:174
sofia/external/2505555555@456.456.456.456 Standard REPORTING, cause:
NORMAL_TEMPORARY_FAILURE
2016-09-20 17:37:35.329553 [DEBUG] switch_core_state_machine.c:897
(sofia/external/2505555555@456.456.456.456) State REPORTING going to sleep
2016-09-20 17:37:35.329553 [DEBUG] switch_core_state_machine.c:569
(sofia/external/2505555555@456.456.456.456) State Change CS_REPORTING ->
CS_DESTROY
2016-09-20 17:37:35.329553 [DEBUG] switch_core_session.c:1647 Session 5
(sofia/external/2505555555@456.456.456.456) Locked, Waiting on external
entities
2016-09-20 17:37:35.329553 [NOTICE] switch_core_session.c:1665 Session 5
(sofia/external/2505555555@456.456.456.456) Ended
2016-09-20 17:37:35.329553 [NOTICE] switch_core_session.c:1669 Close
Channel sofia/external/2505555555@456.456.456.456 [CS_DESTROY]
2016-09-20 17:37:35.329553 [DEBUG] switch_core_state_machine.c:700
(sofia/external/2505555555@456.456.456.456) Running State Change CS_DESTROY
2016-09-20 17:37:35.329553 [DEBUG] switch_core_state_machine.c:710
(sofia/external/2505555555@456.456.456.456) State DESTROY
2016-09-20 17:37:35.329553 [DEBUG] mod_sofia.c:343 sofia/external/2505555555
@456.456.456.456 SOFIA DESTROY
2016-09-20 17:37:35.329553 [DEBUG] switch_core_state_machine.c:181
sofia/external/2505555555@456.456.456.456 Standard DESTROY
2016-09-20 17:37:35.329553 [DEBUG] switch_core_state_machine.c:710
(sofia/external/2505555555@456.456.456.456) State DESTROY going to sleep
recv 824 bytes from udp/[72.143.224.138]:20365 at 17:37:35.371629:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 123.123.123.123;rport=5060;branch=z9hG4bK0DU6aXj2FvHBp
   Via: SIP/2.0/UDP 123.123.123.123;rport=5060;branch=z9hG4bKvXKtj06r89vca
   Contact: <sip:2001@72.143.224.138:20365;transport=UDP>
   To: <sip:2001@72.143.224.138:20365;transport=UDP;rinstance=
d85e769961280fbc>;tag=14496d0a
   From: "SOKAMLOOPS BC " <sip:2505555555@sipa.test.com>;tag=vDHFU74UXyNmS
   Call-ID: 65dd6ddc-fa36-1234-b68d-1803730b83c5
   CSeq: 96873063 INVITE
   Content-Type: application/sdp
   User-Agent: Zoiper rv2.8.6
   Allow-Events: presence, kpml, talk
   Content-Length: 245

   v=0
   o=Zoiper 0 2 IN IP4 25.171.247.182
   s=Zoiper
   c=IN IP4 25.171.247.182
   t=0 0
   m=audio 54200 RTP/AVP 0 3 8 101
   a=rtpmap:0 PCMU/8000
   a=rtpmap:3 GSM/8000
   a=rtpmap:8 PCMA/8000
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-16
   a=sendrecv
   ------------------------------------------------------------------------
2016-09-20 17:37:35.369573 [DEBUG] sofia.c:6963 Channel sofia/internal/
2001@72.143.224.138:20365 entering state [completing][200]
2016-09-20 17:37:35.369573 [DEBUG] sofia.c:6973 Remote SDP:
v=0
o=Zoiper 0 2 IN IP4 25.171.247.182
s=Zoiper
c=IN IP4 25.171.247.182
t=0 0
m=audio 54200 RTP/AVP 0 3 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:3 GSM/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16

send 446 bytes to udp/[72.143.224.138]:20365 at 17:37:35.373931:
   ------------------------------------------------------------------------
   ACK sip:2001@72.143.224.138:20365;transport=UDP SIP/2.0
   Via: SIP/2.0/UDP 123.123.123.123;rport;branch=z9hG4bK1pmZcr35c57XH
   Max-Forwards: 70
   From: "SOKAMLOOPS BC " <sip:2505555555@sipa.test.com>;tag=vDHFU74UXyNmS
   To: <sip:2001@72.143.224.138:20365;transport=UDP;rinstance=
d85e769961280fbc>;tag=14496d0a
   Call-ID: 65dd6ddc-fa36-1234-b68d-1803730b83c5
   CSeq: 96873063 ACK
   Contact: <sip:2001@123.123.123.123:5060>
   Content-Length: 0

   ------------------------------------------------------------------------
2016-09-20 17:37:35.369573 [DEBUG] sofia.c:6963 Channel sofia/internal/
2001@72.143.224.138:20365 entering state [ready][200]
2016-09-20 17:37:35.369573 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2016-09-20 17:37:35.369573 [DEBUG] switch_core_media.c:4336 Audio Codec
Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2016-09-20 17:37:35.369573 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2016-09-20 17:37:35.369573 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2016-09-20 17:37:35.369573 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2016-09-20 17:37:35.369573 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
2016-09-20 17:37:35.369573 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [GSM:3:8000:20:13200:1]/[G722:9:8000:20:64000:1]
2016-09-20 17:37:35.369573 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
2016-09-20 17:37:35.369573 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [GSM:3:8000:20:13200:1]/[GSM:3:8000:20:13200:1]
2016-09-20 17:37:35.369573 [DEBUG] switch_core_media.c:4336 Audio Codec
Compare [GSM:3:8000:20:13200:1] ++++ is saved as a match
2016-09-20 17:37:35.369573 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2016-09-20 17:37:35.369573 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2016-09-20 17:37:35.369573 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2016-09-20 17:37:35.369573 [DEBUG] switch_core_media.c:4336 Audio Codec
Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2016-09-20 17:37:35.369573 [DEBUG] switch_core_media.c:4281 Audio Codec
Compare [PCMA:8:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2016-09-20 17:37:35.369573 [DEBUG] switch_core_media.c:4197 Set
telephone-event payload to 101@8000
2016-09-20 17:37:35.369573 [DEBUG] switch_core_media.c:4542 Set
telephone-event payload to 101@8000
2016-09-20 17:37:35.369573 [DEBUG] switch_core_media.c:4601 sofia/internal/
2001@72.143.224.138:20365 Set 2833 dtmf send payload to 101 recv payload to
101
recv 804 bytes from udp/[72.143.224.138]:20365 at 17:37:56.351865:
   ------------------------------------------------------------------------
   REGISTER sip:sipa.test.com;transport=UDP SIP/2.0
   Via: SIP/2.0/UDP 72.143.224.138:20365;branch=z9hG4bK-524287-1---
b9edf472a8bb6736;rport
   Max-Forwards: 70
   Contact: <sip:2001@72.143.224.138:20365;transport=UDP;rinstance=
d85e769961280fbc>
   To: <sip:2001@sipa.test.com;transport=UDP>
   From: <sip:2001@sipa.test.com;transport=UDP>;tag=485b613a
   Call-ID: Zp_dAlhQHhOnxlCOqIOQSQ..
   CSeq: 36 REGISTER
   Expires: 60
   User-Agent: Zoiper rv2.8.6
   Authorization: Digest username="2001",realm="sipa.test.com
",nonce="835df416-7f93-11e6-828d-059a9340be7a",uri="sip:sipa.test.com;
transport=UDP",response="a871aaeeeb8e395bd25baa2bc35e1f85",cnonce="
b671a0e31b5669bb233523be0b0c5a2a",nc=00000002,qop=auth,algorithm=MD5
   Allow-Events: presence, kpml, talk
   Content-Length: 0

   ------------------------------------------------------------------------
2016-09-20 17:37:56.349627 [WARNING] sofia_reg.c:1791 SIP auth challenge
(REGISTER) on sofia profile 'internal' for [2001@sipa.test.com] from ip
72.143.224.138
send 644 bytes to udp/[72.143.224.138]:20365 at 17:37:56.354596:
   ------------------------------------------------------------------------
   SIP/2.0 401 Unauthorized
   Via: SIP/2.0/UDP 72.143.224.138:20365;branch=z9hG4bK-524287-1---
b9edf472a8bb6736;rport=20365
   From: <sip:2001@sipa.test.com;transport=UDP>;tag=485b613a
   To: <sip:2001@sipa.test.com;transport=UDP>;tag=XZrpgyy7gUc8m
   Call-ID: Zp_dAlhQHhOnxlCOqIOQSQ..
   CSeq: 36 REGISTER
   User-Agent: FreeSWITCH
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, path, replaces
   WWW-Authenticate: Digest realm="sipa.test.com",
nonce="a3a0e382-7f93-11e6-8291-059a9340be7a", stale=true, algorithm=MD5,
qop="auth"
   Content-Length: 0

   ------------------------------------------------------------------------
recv 804 bytes from udp/[72.143.224.138]:20365 at 17:37:56.403816:
   ------------------------------------------------------------------------
   REGISTER sip:sipa.test.com;transport=UDP SIP/2.0
   Via: SIP/2.0/UDP 72.143.224.138:20365;branch=z9hG4bK-524287-1---
2143d80bb83fa0aa;rport
   Max-Forwards: 70
   Contact: <sip:2001@72.143.224.138:20365;transport=UDP;rinstance=
d85e769961280fbc>
   To: <sip:2001@sipa.test.com;transport=UDP>
   From: <sip:2001@sipa.test.com;transport=UDP>;tag=485b613a
   Call-ID: Zp_dAlhQHhOnxlCOqIOQSQ..
   CSeq: 37 REGISTER
   Expires: 60
   User-Agent: Zoiper rv2.8.6
   Authorization: Digest username="2001",realm="sipa.test.com
",nonce="a3a0e382-7f93-11e6-8291-059a9340be7a",uri="sip:sipa.test.com;
transport=UDP",response="0ee4450e941de381ecc6503656ab8a08",cnonce="
577702d5d1c07839b64fecf4f308659f",nc=00000001,qop=auth,algorithm=MD5
   Allow-Events: presence, kpml, talk
   Content-Length: 0

   ------------------------------------------------------------------------
send 623 bytes to udp/[72.143.224.138]:20365 at 17:37:56.410869:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 72.143.224.138:20365;branch=z9hG4bK-524287-1---
2143d80bb83fa0aa;rport=20365
   From: <sip:2001@sipa.test.com;transport=UDP>;tag=485b613a
   To: <sip:2001@sipa.test.com;transport=UDP>;tag=y8HFjSFBe42tg
   Call-ID: Zp_dAlhQHhOnxlCOqIOQSQ..
   CSeq: 37 REGISTER
   Contact: <sip:2001@72.143.224.138:20365;transport=UDP;rinstance=
d85e769961280fbc>;expires=60
   Date: Wed, 21 Sep 2016 00:37:56 GMT
   User-Agent: FreeSWITCH
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, path, replaces
   Content-Length: 0

   ------------------------------------------------------------------------
2016-09-20 17:37:56.449557 [DEBUG] switch_pgsql.c:415 Query (select 1,
read_flags, count(read_epoch) from voicemail_msgs where username='2001' and
domain='sipa.test.com' and in_folder='inbox' and read_epoch=0 group by
read_flags union select 0, read_flags, count(read_epoch) from
voicemail_msgs where username='2001' and domain='sipa.test.com' and
in_folder='inbox' and read_epoch<>0 group by read_flags;) returned
PGRES_FATAL_ERROR
2016-09-20 17:37:56.449557 [ERR] switch_core_sqldb.c:1178 ERR: [select 1,
read_flags, count(read_epoch) from voicemail_msgs where username='2001' and
domain='sipa.test.com' and in_folder='inbox' and read_epoch=0 group by
read_flags union select 0, read_flags, count(read_epoch) from
voicemail_msgs where username='2001' and domain='sipa.test.com' and
in_folder='inbox' and read_epoch<>0 group by read_flags;]
[ERROR:  relation "voicemail_msgs" does not exist
LINE 1: select 1, read_flags, count(read_epoch) from voicemail_msgs ...
                                                     ^
]
2016-09-20 17:37:56.449557 [ERR] switch_core_sqldb.c:1178 ERR: [select 1,
read_flags, count(read_epoch) from voicemail_msgs where username='2001' and
domain='sipa.test.com' and in_folder='inbox' and read_epoch=0 group by
read_flags union select 0, read_flags, count(read_epoch) from
voicemail_msgs where username='2001' and domain='sipa.test.com' and
in_folder='inbox' and read_epoch<>0 group by read_flags;]
[ERROR:  relation "voicemail_msgs" does not exist
LINE 1: select 1, read_flags, count(read_epoch) from voicemail_msgs ...
                                                     ^
]
send 933 bytes to udp/[72.143.224.138]:20365 at 17:37:56.452249:
   ------------------------------------------------------------------------
   NOTIFY sip:2001@72.143.224.138:20365;transport=UDP;rinstance=d85e769961280fbc
SIP/2.0
   Via: SIP/2.0/UDP 123.123.123.123;rport;branch=z9hG4bK2ZDreKm99DygD
   Max-Forwards: 70
   From: <sip:2001@123.123.123.123>;tag=ZHB8Km0eBDSDc
   To: <sip:2001@123.123.123.123>
   Call-ID: 7b0e4a51-fa36-1234-008f-1803730b8a29
   CSeq: 96873074 NOTIFY
   Contact: <sip:mod_sofia@123.123.123.123:5060>
   User-Agent: FreeSWITCH
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, path, replaces
   Event: message-summary
   Allow-Events: talk, hold, conference, presence, as-feature-event,
dialog, line-seize, call-info, sla, include-session-description,
presence.winfo, message-summary, refer
   Subscription-State: terminated;reason=noresource
   Content-Type: application/simple-message-summary
   Content-Length: 74

   Messages-Waiting: no
   Message-Account: sip:2001@sipa.test.com

   ------------------------------------------------------------------------
recv 342 bytes from udp/[72.143.224.138]:20365 at 17:37:56.495779:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 123.123.123.123;rport=5060;branch=z9hG4bK2ZDreKm99DygD
   Contact: <sip:25.171.247.182:32731>
   To: <sip:2001@123.123.123.123>;tag=78ac3037
   From: <sip:2001@123.123.123.123>;tag=ZHB8Km0eBDSDc
   Call-ID: 7b0e4a51-fa36-1234-008f-1803730b8a29
   CSeq: 96873074 NOTIFY
   User-Agent: Zoiper rv2.8.6
   Content-Length: 0

   ------------------------------------------------------------------------
recv 402 bytes from udp/[456.456.456.456]:5060 at 17:38:16.100468:
   ------------------------------------------------------------------------
   BYE sip:7786962265@123.123.123.123:5080;transport=udp SIP/2.0
   Via: SIP/2.0/UDP 456.456.456.456:5060;branch=z9hG4bK0966e536;rport
   Max-Forwards: 70
   From: "SOKAMLOOPS BC " <sip:2505555555@456.456.456.456>;tag=as755f2144
   To: <sip:7786962265@123.123.123.123:5080>;tag=FgXZ7SQvN5XQF
   Call-ID: 3a3825c20a395c2f02a629bd22ef969c@456.456.456.456:5060
   CSeq: 103 BYE
   User-Agent: Itelnetworks
   Content-Length: 0

   ------------------------------------------------------------------------
send 481 bytes to udp/[456.456.456.456]:5060 at 17:38:16.100594:
   ------------------------------------------------------------------------
   SIP/2.0 481 Call Does Not Exist
   Via: SIP/2.0/UDP 456.456.456.456:5060;branch=z9hG4bK0966e536;rport=5060
   From: "SOKAMLOOPS BC " <sip:2505555555@456.456.456.456>;tag=as755f2144
   To: <sip:7786962265@123.123.123.123:5080>;tag=FgXZ7SQvN5XQF
   Call-ID: 3a3825c20a395c2f02a629bd22ef969c@456.456.456.456:5060
   CSeq: 103 BYE
   User-Agent: FreeSWITCH
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
REGISTER, REFER, NOTIFY
   Supported: timer, path, replaces
   Content-Length: 0

   ------------------------------------------------------------------------
recv 487 bytes from udp/[72.143.224.138]:20365 at 17:38:18.222019:
   ------------------------------------------------------------------------
   BYE sip:2001@123.123.123.123:5060 SIP/2.0
   Via: SIP/2.0/UDP 72.143.224.138:20365;branch=z9hG4bK-524287-1---
4e026360bb72799f;rport
   Max-Forwards: 70
   Contact: <sip:2001@72.143.224.138:20365;transport=UDP>
   To: "SOKAMLOOPS BC " <sip:2505555555@sipa.test.com>;tag=vDHFU74UXyNmS
   From: <sip:2001@72.143.224.138:20365;transport=UDP;rinstance=
d85e769961280fbc>;tag=14496d0a
   Call-ID: 65dd6ddc-fa36-1234-b68d-1803730b83c5
   CSeq: 2 BYE
   User-Agent: Zoiper rv2.8.6
   Content-Length: 0

   ------------------------------------------------------------------------
2016-09-20 17:38:18.209629 [NOTICE] sofia.c:1011 Hangup sofia/internal/
2001@72.143.224.138:20365 [CS_RESET] [NORMAL_CLEARING]
2016-09-20 17:38:18.209629 [DEBUG] switch_core_state_machine.c:543
(sofia/internal/2001@72.143.224.138:20365) Running State Change CS_HANGUP
send 532 bytes to udp/[72.143.224.138]:20365 at 17:38:18.222838:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 72.143.224.138:20365;branch=z9hG4bK-524287-1---
4e026360bb72799f;rport=20365
   From: <sip:2001@72.143.224.138:20365;transport=UDP;rinstance=
d85e769961280fbc>;tag=14496d0a
   To: "SOKAMLOOPS BC " <sip:2505555555@sipa.test.com>;tag=vDHFU74UXyNmS
   Call-ID: 65dd6ddc-fa36-1234-b68d-1803730b83c5
   CSeq: 2 BYE
   User-Agent: FreeSWITCH
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
   Supported: timer, path, replaces
   Content-Length: 0

   ------------------------------------------------------------------------
2016-09-20 17:38:18.209629 [DEBUG] switch_core_state_machine.c:809
(sofia/internal/2001@72.143.224.138:20365) Callstate Change DOWN -> HANGUP
2016-09-20 17:38:18.209629 [DEBUG] switch_core_state_machine.c:811
(sofia/internal/2001@72.143.224.138:20365) State HANGUP
2016-09-20 17:38:18.209629 [DEBUG] mod_sofia.c:432 sofia/internal/
2001@72.143.224.138:20365 Overriding SIP cause 480 with 481 from the other
leg
2016-09-20 17:38:18.209629 [DEBUG] mod_sofia.c:438 Channel sofia/internal/
2001@72.143.224.138:20365 hanging up, cause: NORMAL_CLEARING
2016-09-20 17:38:18.209629 [DEBUG] switch_core_state_machine.c:60
sofia/internal/2001@72.143.224.138:20365 Standard HANGUP, cause:
NORMAL_CLEARING
2016-09-20 17:38:18.209629 [DEBUG] switch_core_state_machine.c:811
(sofia/internal/2001@72.143.224.138:20365) State HANGUP going to sleep
2016-09-20 17:38:18.209629 [DEBUG] switch_core_state_machine.c:578
(sofia/internal/2001@72.143.224.138:20365) State Change CS_HANGUP ->
CS_REPORTING
2016-09-20 17:38:18.209629 [DEBUG] switch_core_state_machine.c:543
(sofia/internal/2001@72.143.224.138:20365) Running State Change CS_REPORTING
2016-09-20 17:38:18.209629 [DEBUG] switch_core_state_machine.c:897
(sofia/internal/2001@72.143.224.138:20365) State REPORTING
2016-09-20 17:38:18.209629 [DEBUG] switch_core_state_machine.c:174
sofia/internal/2001@72.143.224.138:20365 Standard REPORTING, cause:
NORMAL_CLEARING
2016-09-20 17:38:18.209629 [DEBUG] switch_core_state_machine.c:897
(sofia/internal/2001@72.143.224.138:20365) State REPORTING going to sleep
2016-09-20 17:38:18.209629 [DEBUG] switch_core_state_machine.c:569
(sofia/internal/2001@72.143.224.138:20365) State Change CS_REPORTING ->
CS_DESTROY
2016-09-20 17:38:18.209629 [DEBUG] switch_core_session.c:1647 Session 6
(sofia/internal/2001@72.143.224.138:20365) Locked, Waiting on external
entities
2016-09-20 17:38:18.209629 [NOTICE] switch_core_session.c:1665 Session 6
(sofia/internal/2001@72.143.224.138:20365) Ended
2016-09-20 17:38:18.209629 [NOTICE] switch_core_session.c:1669 Close
Channel sofia/internal/2001@72.143.224.138:20365 [CS_DESTROY]
2016-09-20 17:38:18.209629 [DEBUG] switch_core_state_machine.c:700
(sofia/internal/2001@72.143.224.138:20365) Running State Change CS_DESTROY
2016-09-20 17:38:18.209629 [DEBUG] switch_core_state_machine.c:710
(sofia/internal/2001@72.143.224.138:20365) State DESTROY
2016-09-20 17:38:18.209629 [DEBUG] mod_sofia.c:343 sofia/internal/
2001@72.143.224.138:20365 SOFIA DESTROY
2016-09-20 17:38:18.209629 [DEBUG] switch_core_state_machine.c:181
sofia/internal/2001@72.143.224.138:20365 Standard DESTROY
2016-09-20 17:38:18.209629 [DEBUG] switch_core_state_machine.c:710
(sofia/internal/2001@72.143.224.138:20365) State DESTROY going to sleep
recv 579 bytes from udp/[789.789.789.789]:5060 at 17:38:23.084830:
   ------------------------------------------------------------------------
   OPTIONS sip:123.123.123.123 SIP/2.0
   Via: SIP/2.0/UDP 789.789.789.789:5060;branch=z9hG4bK225c5987;rport
   Max-Forwards: 70
   From: "Unknown" <sip:Unknown@789.789.789.789>;tag=as6a493bca
   To: <sip:123.123.123.123>
   Contact: <sip:Unknown@789.789.789.789:5060>
   Call-ID: 429157a261083a5c509facc67aa348df@789.789.789.789:5060
   CSeq: 102 OPTIONS
   User-Agent: Itelnetworks
   Date: Wed, 21 Sep 2016 00:38:23 GMT
   Session-Expires: 7200
   Min-SE: 90
   Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY,
INFO, PUBLISH, MESSAGE
   Supported: replaces, timer
   Content-Length: 0

   ------------------------------------------------------------------------
send 555 bytes to udp/[789.789.789.789]:5060 at 17:38:23.085328:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 789.789.789.789:5060;branch=z9hG4bK225c5987;rport=5060
   From: "Unknown" <sip:Unknown@789.789.789.789>;tag=as6a493bca
   To: <sip:123.123.123.123>;tag=3He4KBmtStScF
   Call-ID: 429157a261083a5c509facc67aa348df@789.789.789.789:5060
   CSeq: 102 OPTIONS
   Contact: <sip:123.123.123.123:5080>
   User-Agent: FreeSWITCH
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
REGISTER, REFER, NOTIFY
   Supported: timer, path, replaces
   Allow-Events: talk, hold, conference, refer
   Content-Length: 0

   ------------------------------------------------------------------------
recv 529 bytes from udp/[456.456.456.456]:5060 at 17:38:26.118048:
   ------------------------------------------------------------------------
   OPTIONS sip:123.123.123.123 SIP/2.0
   Via: SIP/2.0/UDP 456.456.456.456:5060;branch=z9hG4bK1e72e437;rport
   Max-Forwards: 70
   From: "Unknown" <sip:Unknown@456.456.456.456>;tag=as3e625c42
   To: <sip:123.123.123.123>
   Contact: <sip:Unknown@456.456.456.456:5060>
   Call-ID: 3853daf95e839ae9006385ce4562951b@456.456.456.456:5060
   CSeq: 102 OPTIONS
   User-Agent: Itelnetworks
   Date: Wed, 21 Sep 2016 00:38:26 GMT
   Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY,
INFO, PUBLISH, MESSAGE
   Supported: replaces
   Content-Length: 0

   ------------------------------------------------------------------------
send 549 bytes to udp/[456.456.456.456]:5060 at 17:38:26.118375:
   ------------------------------------------------------------------------
   SIP/2.0 200 OK
   Via: SIP/2.0/UDP 456.456.456.456:5060;branch=z9hG4bK1e72e437;rport=5060
   From: "Unknown" <sip:Unknown@456.456.456.456>;tag=as3e625c42
   To: <sip:123.123.123.123>;tag=4t7vN64Xp3FZa
   Call-ID: 3853daf95e839ae9006385ce4562951b@456.456.456.456:5060
   CSeq: 102 OPTIONS
   Contact: <sip:123.123.123.123:5080>
   User-Agent: FreeSWITCH
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE,
REGISTER, REFER, NOTIFY
   Supported: timer, path, replaces
   Allow-Events: talk, hold, conference, refer
   Content-Length: 0

   ------------------------------------------------------------------------

-- 
*Tanner Kerr* | Junior Developer / Support Technician | *iTel.com
<http://www.itel.com/> *
*1.888.899.4835 <1.888.899.4835> *(ext:1027)