span style="color: cornflowerblue; font-weight: bold;"> 2019-04-02 18:21:55.692810 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1003@riverwalk.cust.tellarc.com [27a10d0e-9622-4210-af84-ca802ece35a8]
2019-04-02 18:21:55.692810 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@riverwalk.cust.tellarc.com) Running State Change CS_NEW (Cur 5 Tot 31356)
2019-04-02 18:21:55.692810 [DEBUG] sofia.c:10092 sofia/internal/1003@riverwalk.cust.tellarc.com receiving invite from 96.65.187.108:8133 version: 1.8.3 -4-4d4c454d3e 64bit
2019-04-02 18:21:55.692810 [DEBUG] sofia.c:10263 IP 96.65.187.108 Rejected by acl "domains". Falling back to Digest auth.
2019-04-02 18:21:55.692810 [WARNING] sofia_reg.c:1796 SIP auth challenge (INVITE) on sofia profile 'internal' for [*97@riverwalk.cust.tellarc.com] from ip 96.65.187.108
2019-04-02 18:21:55.692810 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/1003@riverwalk.cust.tellarc.com) State NEW
2019-04-02 18:21:55.692810 [DEBUG] sofia.c:2413 detaching session 27a10d0e-9622-4210-af84-ca802ece35a8
2019-04-02 18:21:55.852848 [DEBUG] sofia.c:2522 Re-attaching to session 27a10d0e-9622-4210-af84-ca802ece35a8
2019-04-02 18:21:55.852848 [DEBUG] sofia.c:10092 sofia/internal/1003@riverwalk.cust.tellarc.com receiving invite from 96.65.187.108:8133 version: 1.8.3 -4-4d4c454d3e 64bit
2019-04-02 18:21:55.852848 [DEBUG] sofia.c:10263 IP 96.65.187.108 Rejected by acl "domains". Falling back to Digest auth.
2019-04-02 18:21:55.872794 [DEBUG] sofia.c:11400 Setting NAT mode based on via received
2019-04-02 18:21:55.872794 [DEBUG] sofia.c:7291 Channel sofia/internal/1003@riverwalk.cust.tellarc.com entering state [received][100]
2019-04-02 18:21:55.872794 [DEBUG] sofia.c:7301 Remote SDP:
v=0
o=- 114909373 114909373 IN IP4 192.168.1.67
s=-
c=IN IP4 192.168.1.67
t=0 0
m=audio 16468 RTP/AVP 0 2 8 9 18 96 97 98 101
a=rtpmap:0 PCMU/8000
a=rtpmap:2 G726-32/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=rtpmap:18 G729a/8000
a=rtpmap:96 G726-40/8000
a=rtpmap:97 G726-24/8000
a=rtpmap:98 G726-16/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
2019-04-02 18:21:55.872794 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
2019-04-02 18:21:55.872794 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-04-02 18:21:55.872794 [DEBUG] switch_core_media.c:5533 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2019-04-02 18:21:55.872794 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [G726-32:2:8000:20:0:1]/[opus:116:48000:20:0:1]
2019-04-02 18:21:55.872794 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [G726-32:2:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
2019-04-02 18:21:55.872794 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
2019-04-02 18:21:55.872794 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-04-02 18:21:55.872794 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1]
2019-04-02 18:21:55.872794 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-04-02 18:21:55.872794 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [G729a:18:8000:20:8000:1]/[opus:116:48000:20:0:1]
2019-04-02 18:21:55.872794 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [G729a:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2019-04-02 18:21:55.872794 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [G726-40:96:8000:20:0:1]/[opus:116:48000:20:0:1]
2019-04-02 18:21:55.872794 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [G726-40:96:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
2019-04-02 18:21:55.872794 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [G726-24:97:8000:20:0:1]/[opus:116:48000:20:0:1]
2019-04-02 18:21:55.872794 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [G726-24:97:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
2019-04-02 18:21:55.872794 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [G726-16:98:8000:20:0:1]/[opus:116:48000:20:0:1]
2019-04-02 18:21:55.872794 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [G726-16:98:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
2019-04-02 18:21:55.872794 [DEBUG] switch_core_media.c:5394 Set telephone-event payload to 101@8000
2019-04-02 18:21:55.872794 [DEBUG] switch_core_media.c:3781 Set Codec sofia/internal/1003@riverwalk.cust.tellarc.com PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2019-04-02 18:21:55.872794 [DEBUG] switch_core_codec.c:111 sofia/internal/1003@riverwalk.cust.tellarc.com Original read codec set to PCMU:0
2019-04-02 18:21:55.872794 [DEBUG] switch_core_media.c:5737 Set telephone-event payload to 101@8000
2019-04-02 18:21:55.872794 [DEBUG] switch_core_media.c:5795 sofia/internal/1003@riverwalk.cust.tellarc.com Set 2833 dtmf send payload to 101 recv payload to 101
2019-04-02 18:21:55.872794 [DEBUG] sofia.c:7716 (sofia/internal/1003@riverwalk.cust.tellarc.com) State Change CS_NEW -> CS_INIT
2019-04-02 18:21:55.872794 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@riverwalk.cust.tellarc.com) Running State Change CS_INIT (Cur 5 Tot 31356)
2019-04-02 18:21:55.872794 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1003@riverwalk.cust.tellarc.com) State INIT
2019-04-02 18:21:55.872794 [DEBUG] mod_sofia.c:93 sofia/internal/1003@riverwalk.cust.tellarc.com SOFIA INIT
2019-04-02 18:21:55.872794 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1003@riverwalk.cust.tellarc.com Standard INIT
2019-04-02 18:21:55.872794 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1003@riverwalk.cust.tellarc.com) State Change CS_INIT -> CS_ROUTING
2019-04-02 18:21:55.872794 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1003@riverwalk.cust.tellarc.com) State INIT going to sleep
2019-04-02 18:21:55.872794 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@riverwalk.cust.tellarc.com) Running State Change CS_ROUTING (Cur 5 Tot 31356)
2019-04-02 18:21:55.872794 [DEBUG] switch_channel.c:2249 (sofia/internal/1003@riverwalk.cust.tellarc.com) Callstate Change DOWN -> RINGING
2019-04-02 18:21:55.872794 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1003@riverwalk.cust.tellarc.com) State ROUTING
2019-04-02 18:21:55.872794 [DEBUG] mod_sofia.c:154 sofia/internal/1003@riverwalk.cust.tellarc.com SOFIA ROUTING
2019-04-02 18:21:55.872794 [DEBUG] switch_core_state_machine.c:236 sofia/internal/1003@riverwalk.cust.tellarc.com Standard ROUTING
2019-04-02 18:21:55.872794 [INFO] mod_dialplan_xml.c:637 Processing Ilissa <1003>->*97 in context riverwalk.cust.tellarc.com
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->user_exists] continue=true
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (PASS) [user_exists] () =~ // break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
EXECUTE sofia/internal/1003@riverwalk.cust.tellarc.com set(user_exists=false)
2019-04-02 18:21:55.872794 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1003@riverwalk.cust.tellarc.com [user_exists]=[false]
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->user_exists] continue=true
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (PASS) [user_exists] () =~ // break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
EXECUTE sofia/internal/1003@riverwalk.cust.tellarc.com set(user_exists=false)
2019-04-02 18:21:55.872794 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1003@riverwalk.cust.tellarc.com [user_exists]=[false]
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->caller-details] continue=true
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (PASS) [caller-details] ${caller_destination}() =~ /^$/ break=never
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Action set(caller_destination=${destination_number}) INLINE
EXECUTE sofia/internal/1003@riverwalk.cust.tellarc.com set(caller_destination=*97)
2019-04-02 18:21:55.872794 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1003@riverwalk.cust.tellarc.com [caller_destination]=[*97]
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Action set(caller_id_name=${caller_id_name}) INLINE
EXECUTE sofia/internal/1003@riverwalk.cust.tellarc.com set(caller_id_name=1003)
2019-04-02 18:21:55.872794 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1003@riverwalk.cust.tellarc.com [caller_id_name]=[1003]
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Action set(caller_id_number=${caller_id_number}) INLINE
EXECUTE sofia/internal/1003@riverwalk.cust.tellarc.com set(caller_id_number=1003)
2019-04-02 18:21:55.872794 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1003@riverwalk.cust.tellarc.com [caller_id_number]=[1003]
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->call-direction] continue=true
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [call-direction] ${call_direction}() =~ /^(inbound|outbound|local)$/ break=never
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com ANTI-Action set(call_direction=local)
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->variables] continue=true
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (PASS) [variables] () =~ // break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Action export(origination_callee_id_name=${destination_number})
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Action set(timezone=America/New_York) INLINE
EXECUTE sofia/internal/1003@riverwalk.cust.tellarc.com set(timezone=America/New_York)
2019-04-02 18:21:55.872794 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1003@riverwalk.cust.tellarc.com [timezone]=[America/New_York]
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->is_local] continue=true
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (PASS) [is_local] () =~ // break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Action lua(app.lua is_local)
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->is_loopback] continue=
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [is_loopback] ${is_follow_me_loopback}() =~ /true/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->user_record] continue=true
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (PASS) [user_record] () =~ // break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Action set(user_record=${user_data ${destination_number}@${domain_name} var user_record}) INLINE
EXECUTE sofia/internal/1003@riverwalk.cust.tellarc.com set(user_record=)
2019-04-02 18:21:55.912891 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1003@riverwalk.cust.tellarc.com [user_record]=[UNDEF]
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
EXECUTE sofia/internal/1003@riverwalk.cust.tellarc.com set(from_user_exists=true)
2019-04-02 18:21:55.912891 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1003@riverwalk.cust.tellarc.com [from_user_exists]=[true]
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [user_record] ${call_direction}() =~ /^inbound$/ break=never
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [user_record] ${call_direction}() =~ /^outbound$/ break=never
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [user_record] ${call_direction}() =~ /^local$/ break=never
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Action set(from_user_record=${user_data ${sip_from_user}@${sip_from_host} var user_record}) INLINE
EXECUTE sofia/internal/1003@riverwalk.cust.tellarc.com set(from_user_record=)
2019-04-02 18:21:55.912891 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1003@riverwalk.cust.tellarc.com [from_user_record]=[UNDEF]
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [user_record] ${call_direction}() =~ /^inbound$/ break=never
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [user_record] ${call_direction}() =~ /^outbound$/ break=never
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [user_record] ${call_direction}() =~ /^local$/ break=never
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->redial] continue=true
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [redial] destination_number(*97) =~ /^(redial|\*870)$/ break=on-true
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (PASS) [redial] () =~ // break=never
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->speed_dial] continue=false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [speed_dial] destination_number(*97) =~ /^\*0(.*)$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->default_caller_id] continue=true
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [default_caller_id] ${emergency_caller_id_number}(5616977712) =~ /^$/ break=never
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [default_caller_id] ${outbound_caller_id_number}(5616977712) =~ /^$/ break=never
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->911-v1voip] continue=false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [911-v1voip] destination_number(*97) =~ /^(911)$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->teli.911-global] continue=false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (PASS) [teli.911-global] ${user_exists}(false) =~ /false/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [teli.911-global] destination_number(*97) =~ /^(911|933)$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->ring group] continue=
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [ring group] destination_number(*97) =~ /^7501$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->sbc0.7d] continue=false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [sbc0.7d] destination_number(*97) =~ /^(\d{7})$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->sbc0.d4] continue=false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [sbc0.d4] destination_number(*97) =~ /^(1?411)$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->fax] continue=true
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [fax] destination_number(*97) =~ /^919191?(\d{10})$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->10-11-mix] continue=false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [10-11-mix] destination_number(*97) =~ /^\+?1?(\d{10})$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->agent_status] continue=false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [agent_status] destination_number(*97) =~ /^\*22$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->agent_status_id] continue=false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [agent_status_id] destination_number(*97) =~ /^\*23$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->group-intercept] continue=false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [group-intercept] destination_number(*97) =~ /^\*8$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->page-extension] continue=false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [page-extension] destination_number(*97) =~ /^\*8(\d{2,7})$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->eavesdrop] continue=false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [eavesdrop] destination_number(*97) =~ /^\*33(\d{2,7})$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->call_privacy] continue=false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [call_privacy] destination_number(*97) =~ /^\*67(\d+)$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->call_return] continue=false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [call_return] destination_number(*97) =~ /^\*69$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->intercept-ext] continue=false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [intercept-ext] destination_number(*97) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->intercept-ext-polycom] continue=false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [intercept-ext-polycom] destination_number(*97) =~ /^\*97(\d+)$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->extension_queue] continue=false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [extension_queue] destination_number(*97) =~ /^\*800(.*)$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->Riverwalk-Main] continue=true
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [Riverwalk-Main] destination_number(*97) =~ /^7601$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->dx] continue=false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [dx] destination_number(*97) =~ /^dx$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->att_xfer] continue=false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [att_xfer] destination_number(*97) =~ /^att_xfer$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->extension-to-voicemail] continue=false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [extension-to-voicemail] ${user_exists}(false) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->send_to_voicemail] continue=false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [send_to_voicemail] destination_number(*97) =~ /^\*99(\d{2,7})$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->Riverwalk-fax] continue=false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [Riverwalk-fax] destination_number(*97) =~ /^7901$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->extension-to-voicemail] continue=false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (PASS) [extension-to-voicemail] username(1003) =~ /^1003$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [extension-to-voicemail] destination_number(*97) =~ /^1003$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->xfer_vm] continue=false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [xfer_vm] destination_number(*97) =~ /^xfer_vm$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->vmain] continue=false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (FAIL) [vmain] destination_number(*97) =~ /^vmain$|^\*4000$|^\*98$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com parsing [riverwalk.cust.tellarc.com->vmain_user] continue=false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Regex (PASS) [vmain_user] destination_number(*97) =~ /^\*97$/ break=on-false
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Action answer()
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Action sleep(1000)
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Action set(voicemail_action=check)
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Action set(voicemail_id=${caller_id_number})
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Action set(voicemail_profile=default)
Dialplan: sofia/internal/1003@riverwalk.cust.tellarc.com Action lua(app.lua voicemail)
2019-04-02 18:21:55.912891 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/1003@riverwalk.cust.tellarc.com) State Change CS_ROUTING -> CS_EXECUTE
2019-04-02 18:21:55.912891 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1003@riverwalk.cust.tellarc.com) State ROUTING going to sleep
2019-04-02 18:21:55.912891 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@riverwalk.cust.tellarc.com) Running State Change CS_EXECUTE (Cur 5 Tot 31356)
2019-04-02 18:21:55.912891 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1003@riverwalk.cust.tellarc.com) State EXECUTE
2019-04-02 18:21:55.912891 [DEBUG] mod_sofia.c:209 sofia/internal/1003@riverwalk.cust.tellarc.com SOFIA EXECUTE
2019-04-02 18:21:55.912891 [DEBUG] switch_core_state_machine.c:328 sofia/internal/1003@riverwalk.cust.tellarc.com Standard EXECUTE
EXECUTE sofia/internal/1003@riverwalk.cust.tellarc.com set(call_direction=local)
2019-04-02 18:21:55.912891 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1003@riverwalk.cust.tellarc.com [call_direction]=[local]
EXECUTE sofia/internal/1003@riverwalk.cust.tellarc.com export(origination_callee_id_name=*97)
2019-04-02 18:21:55.912891 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [origination_callee_id_name]=[*97]
EXECUTE sofia/internal/1003@riverwalk.cust.tellarc.com set(RFC2822_DATE=Tue, 02 Apr 2019 18:21:55 -0400)
2019-04-02 18:21:55.912891 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1003@riverwalk.cust.tellarc.com [RFC2822_DATE]=[Tue, 02 Apr 2019 18:21:55 -0400]
EXECUTE sofia/internal/1003@riverwalk.cust.tellarc.com lua(app.lua is_local)
EXECUTE sofia/internal/1003@riverwalk.cust.tellarc.com set(caller_id_name=Riverwalk)
2019-04-02 18:21:55.912891 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1003@riverwalk.cust.tellarc.com [caller_id_name]=[Riverwalk]
EXECUTE sofia/internal/1003@riverwalk.cust.tellarc.com set(effective_caller_id_name=Riverwalk)
2019-04-02 18:21:55.912891 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1003@riverwalk.cust.tellarc.com [effective_caller_id_name]=[Riverwalk]
EXECUTE sofia/internal/1003@riverwalk.cust.tellarc.com set(caller_id_number=5616977712)
2019-04-02 18:21:55.912891 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1003@riverwalk.cust.tellarc.com [caller_id_number]=[5616977712]
EXECUTE sofia/internal/1003@riverwalk.cust.tellarc.com set(effective_caller_id_number=5616977712)
2019-04-02 18:21:55.912891 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1003@riverwalk.cust.tellarc.com [effective_caller_id_number]=[5616977712]
2019-04-02 18:21:55.932800 [DEBUG] switch_cpp.cpp:1187 sofia/internal/1003@riverwalk.cust.tellarc.com destroy/unlink session from object
EXECUTE sofia/internal/1003@riverwalk.cust.tellarc.com hash(insert/riverwalk.cust.tellarc.com-last_dial/5616977712/*97)
EXECUTE sofia/internal/1003@riverwalk.cust.tellarc.com answer()
2019-04-02 18:21:55.932800 [DEBUG] switch_core_media.c:8511 AUDIO RTP [sofia/internal/1003@riverwalk.cust.tellarc.com] 162.208.16.4 port 31794 -> 192.168.1.67 port 16468 codec: 0 ms: 20
2019-04-02 18:21:55.932800 [DEBUG] switch_rtp.c:4300 Starting timer [soft] 160 bytes per 20ms
2019-04-02 18:21:55.932800 [DEBUG] switch_core_media.c:8815 sofia/internal/1003@riverwalk.cust.tellarc.com Set 2833 dtmf send payload to 101
2019-04-02 18:21:55.932800 [DEBUG] switch_core_media.c:8822 sofia/internal/1003@riverwalk.cust.tellarc.com Set 2833 dtmf receive payload to 101
2019-04-02 18:21:55.932800 [DEBUG] switch_core_media.c:8845 sofia/internal/1003@riverwalk.cust.tellarc.com Set rtp dtmf delay to 40
2019-04-02 18:21:55.932800 [DEBUG] mod_sofia.c:881 Local SDP sofia/internal/1003@riverwalk.cust.tellarc.com:
v=0
o=FreeSWITCH 1554211921 1554211922 IN IP4 162.208.16.4
s=FreeSWITCH
c=IN IP4 162.208.16.4
t=0 0
m=audio 31794 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
2019-04-02 18:21:55.932800 [NOTICE] mod_dptools.c:1360 Channel [sofia/internal/1003@riverwalk.cust.tellarc.com] has been answered
2019-04-02 18:21:55.932800 [DEBUG] switch_channel.c:3781 (sofia/internal/1003@riverwalk.cust.tellarc.com) Callstate Change RINGING -> ACTIVE
2019-04-02 18:21:55.932800 [DEBUG] sofia.c:7291 Channel sofia/internal/1003@riverwalk.cust.tellarc.com entering state [completed][200]
EXECUTE sofia/internal/1003@riverwalk.cust.tellarc.com sleep(1000)
2019-04-02 18:21:56.072822 [DEBUG] sofia.c:7291 Channel sofia/internal/1003@riverwalk.cust.tellarc.com entering state [ready][200]
2019-04-02 18:21:56.252825 [INFO] switch_rtp.c:7510 Auto Changing audio port from 192.168.1.67:16468 to 96.65.187.108:9270
EXECUTE sofia/internal/1003@riverwalk.cust.tellarc.com set(voicemail_action=check)
2019-04-02 18:21:56.932810 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1003@riverwalk.cust.tellarc.com [voicemail_action]=[check]
EXECUTE sofia/internal/1003@riverwalk.cust.tellarc.com set(voicemail_id=5616977712)
2019-04-02 18:21:56.932810 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1003@riverwalk.cust.tellarc.com [voicemail_id]=[5616977712]
EXECUTE sofia/internal/1003@riverwalk.cust.tellarc.com set(voicemail_profile=default)
2019-04-02 18:21:56.932810 [DEBUG] mod_dptools.c:1598 SET sofia/internal/1003@riverwalk.cust.tellarc.com [voicemail_profile]=[default]
EXECUTE sofia/internal/1003@riverwalk.cust.tellarc.com lua(app.lua voicemail)
2019-04-02 18:21:56.932810 [DEBUG] switch_cpp.cpp:755 CoreSession::setVariable('playback_terminators', '#')
span style="color: goldenrod; font-weight: bold;"> 2019-04-02 18:21:56.952812 [DEBUG] switch_cpp.cpp:731 CoreSession::hangup
2019-04-02 18:21:56.952812 [NOTICE] switch_cpp.cpp:733 Hangup sofia/internal/1003@riverwalk.cust.tellarc.com [CS_EXECUTE] [NORMAL_CLEARING]
2019-04-02 18:21:56.952812 [DEBUG] switch_cpp.cpp:1187 sofia/internal/1003@riverwalk.cust.tellarc.com destroy/unlink session from object
2019-04-02 18:21:56.952812 [DEBUG] switch_core_session.c:2887 sofia/internal/1003@riverwalk.cust.tellarc.com skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2019-04-02 18:21:56.952812 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1003@riverwalk.cust.tellarc.com) State EXECUTE going to sleep
2019-04-02 18:21:56.952812 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@riverwalk.cust.tellarc.com) Running State Change CS_HANGUP (Cur 5 Tot 31356)
2019-04-02 18:21:56.952812 [DEBUG] switch_core_state_machine.c:847 (sofia/internal/1003@riverwalk.cust.tellarc.com) Callstate Change ACTIVE -> HANGUP
2019-04-02 18:21:56.952812 [DEBUG] switch_core_state_machine.c:849 (sofia/internal/1003@riverwalk.cust.tellarc.com) State HANGUP
2019-04-02 18:21:56.952812 [DEBUG] mod_sofia.c:449 Channel sofia/internal/1003@riverwalk.cust.tellarc.com hanging up, cause: NORMAL_CLEARING
2019-04-02 18:21:56.952812 [DEBUG] mod_sofia.c:502 Sending BYE to sofia/internal/1003@riverwalk.cust.tellarc.com
2019-04-02 18:21:56.952812 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1003@riverwalk.cust.tellarc.com Standard HANGUP, cause: NORMAL_CLEARING
2019-04-02 18:21:56.952812 [DEBUG] switch_core_state_machine.c:849 (sofia/internal/1003@riverwalk.cust.tellarc.com) State HANGUP going to sleep
2019-04-02 18:21:56.952812 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1003@riverwalk.cust.tellarc.com) State Change CS_HANGUP -> CS_REPORTING
2019-04-02 18:21:56.952812 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@riverwalk.cust.tellarc.com) Running State Change CS_REPORTING (Cur 5 Tot 31356)
2019-04-02 18:21:56.952812 [DEBUG] switch_core_state_machine.c:935 (sofia/internal/1003@riverwalk.cust.tellarc.com) State REPORTING
2019-04-02 18:21:57.012818 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1003@riverwalk.cust.tellarc.com Standard REPORTING, cause: NORMAL_CLEARING
2019-04-02 18:21:57.012818 [DEBUG] switch_core_state_machine.c:935 (sofia/internal/1003@riverwalk.cust.tellarc.com) State REPORTING going to sleep
2019-04-02 18:21:57.012818 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1003@riverwalk.cust.tellarc.com) State Change CS_REPORTING -> CS_DESTROY
2019-04-02 18:21:57.012818 [DEBUG] switch_core_session.c:1715 Session 31356 (sofia/internal/1003@riverwalk.cust.tellarc.com) Locked, Waiting on external entities
2019-04-02 18:21:57.012818 [NOTICE] switch_core_session.c:1733 Session 31356 (sofia/internal/1003@riverwalk.cust.tellarc.com) Ended
2019-04-02 18:21:57.012818 [NOTICE] switch_core_session.c:1737 Close Channel sofia/internal/1003@riverwalk.cust.tellarc.com [CS_DESTROY]
2019-04-02 18:21:57.012818 [DEBUG] switch_core_state_machine.c:738 (sofia/internal/1003@riverwalk.cust.tellarc.com) Running State Change CS_DESTROY (Cur 4 Tot 31356)
2019-04-02 18:21:57.012818 [DEBUG] switch_core_state_machine.c:748 (sofia/internal/1003@riverwalk.cust.tellarc.com) State DESTROY
2019-04-02 18:21:57.012818 [DEBUG] mod_sofia.c:354 sofia/internal/1003@riverwalk.cust.tellarc.com SOFIA DESTROY
2019-04-02 18:21:57.012818 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1003@riverwalk.cust.tellarc.com Standard DESTROY
2019-04-02 18:21:57.012818 [DEBUG] switch_core_state_machine.c:748 (sofia/internal/1003@riverwalk.cust.tellarc.com) State DESTROY going to sleep