2020-12-15 11:23:19.247516 [DEBUG] switch_rtp.c:7967 RTP RECV DTMF 1:960
2020-12-15 11:23:19.247516 [INFO] switch_channel.c:522 RECV DTMF 1:960
2020-12-15 11:23:19.247516 [DEBUG] switch_ivr_play_say.c:1933 done playing file /var/lib/freeswitch/recordings/vpbx-stpeters.bitco.co.za/stpeters-holiday.wav
2020-12-15 11:23:19.247516 [DEBUG] switch_ivr_menu.c:378 waiting for 4/5 digits t/o 2000
2020-12-15 11:23:19.347517 [NOTICE] switch_channel.c:1118 New Channel sofia/internal/587@vpbx-stpeters.bitco.co.za [421c0b0a-10ae-42cf-9839-4f62371a0888]
2020-12-15 11:23:19.347517 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/587@vpbx-stpeters.bitco.co.za) Running State Change CS_NEW (Cur 2 Tot 178)
2020-12-15 11:23:19.347517 [DEBUG] sofia.c:10279 sofia/internal/587@vpbx-stpeters.bitco.co.za receiving invite from 41.79.81.110:65476 version: 1.10.3 -release-15-129de34d84 64bit
2020-12-15 11:23:19.347517 [DEBUG] sofia.c:10373 verifying acl "domains" for ip/port 41.79.81.110:0.
2020-12-15 11:23:19.347517 [WARNING] sofia_reg.c:1794 SIP auth challenge (INVITE) on sofia profile 'internal' for [*08@vpbx-stpeters.bitco.co.za] from ip 41.79.81.110
2020-12-15 11:23:19.347517 [DEBUG] switch_core_state_machine.c:604 (sofia/internal/587@vpbx-stpeters.bitco.co.za) State NEW
2020-12-15 11:23:19.347517 [DEBUG] sofia.c:2434 detaching session 421c0b0a-10ae-42cf-9839-4f62371a0888
2020-12-15 11:23:19.347517 [DEBUG] sofia.c:2544 Re-attaching to session 421c0b0a-10ae-42cf-9839-4f62371a0888
2020-12-15 11:23:19.367517 [DEBUG] sofia.c:10279 sofia/internal/587@vpbx-stpeters.bitco.co.za receiving invite from 41.79.81.110:65476 version: 1.10.3 -release-15-129de34d84 64bit
2020-12-15 11:23:19.367517 [DEBUG] sofia.c:10373 verifying acl "domains" for ip/port 41.79.81.110:0.
2020-12-15 11:23:19.367517 [DEBUG] sofia.c:7325 Channel sofia/internal/587@vpbx-stpeters.bitco.co.za entering state [received][100]
2020-12-15 11:23:19.367517 [DEBUG] sofia.c:7335 Remote SDP:
v=0
o=- 3817020199 3817020199 IN IP4 41.79.81.110
s=pjmedia
b=AS:29
t=0 0
a=X-nat:0
m=audio 32274 RTP/AVP 18 101
c=IN IP4 41.79.81.110
b=TIAS:11800
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtcp:32275 IN IP4 41.79.81.110
a=ssrc:578639085 cname:028b1469740d661b

2020-12-15 11:23:19.367517 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
2020-12-15 11:23:19.367517 [DEBUG] switch_core_media.c:5647 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
2020-12-15 11:23:19.367517 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2020-12-15 11:23:19.367517 [DEBUG] switch_core_media.c:5508 Set telephone-event payload to 101@8000
2020-12-15 11:23:19.367517 [DEBUG] switch_core_media.c:3837 Set Codec sofia/internal/587@vpbx-stpeters.bitco.co.za G729/8000 20 ms 160 samples 8000 bits 1 channels
2020-12-15 11:23:19.367517 [DEBUG] switch_core_codec.c:111 sofia/internal/587@vpbx-stpeters.bitco.co.za Original read codec set to G729:18
2020-12-15 11:23:19.367517 [DEBUG] switch_core_media.c:5851 Set telephone-event payload to 101@8000
2020-12-15 11:23:19.367517 [DEBUG] switch_core_media.c:5909 sofia/internal/587@vpbx-stpeters.bitco.co.za Set 2833 dtmf send payload to 101 recv payload to 101
2020-12-15 11:23:19.367517 [DEBUG] sofia.c:7759 (sofia/internal/587@vpbx-stpeters.bitco.co.za) State Change CS_NEW -> CS_INIT
2020-12-15 11:23:19.367517 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/587@vpbx-stpeters.bitco.co.za) Running State Change CS_INIT (Cur 2 Tot 178)
2020-12-15 11:23:19.367517 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/587@vpbx-stpeters.bitco.co.za) State INIT
2020-12-15 11:23:19.367517 [DEBUG] mod_sofia.c:93 sofia/internal/587@vpbx-stpeters.bitco.co.za SOFIA INIT
2020-12-15 11:23:19.367517 [DEBUG] switch_core_state_machine.c:40 sofia/internal/587@vpbx-stpeters.bitco.co.za Standard INIT
2020-12-15 11:23:19.367517 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/587@vpbx-stpeters.bitco.co.za) State Change CS_INIT -> CS_ROUTING
2020-12-15 11:23:19.367517 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/587@vpbx-stpeters.bitco.co.za) State INIT going to sleep
2020-12-15 11:23:19.367517 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/587@vpbx-stpeters.bitco.co.za) Running State Change CS_ROUTING (Cur 2 Tot 178)
2020-12-15 11:23:19.367517 [DEBUG] switch_channel.c:2332 (sofia/internal/587@vpbx-stpeters.bitco.co.za) Callstate Change DOWN -> RINGING
2020-12-15 11:23:19.367517 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/587@vpbx-stpeters.bitco.co.za) State ROUTING
2020-12-15 11:23:19.367517 [DEBUG] mod_sofia.c:154 sofia/internal/587@vpbx-stpeters.bitco.co.za SOFIA ROUTING
2020-12-15 11:23:19.367517 [DEBUG] switch_core_state_machine.c:236 sofia/internal/587@vpbx-stpeters.bitco.co.za Standard ROUTING
2020-12-15 11:23:19.367517 [INFO] mod_dialplan_xml.c:637 Processing 587 <587>->*08 in context vpbx-stpeters.bitco.co.za
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za parsing [vpbx-stpeters.bitco.co.za->user_exists] continue=true
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_exists] ${loopback_leg}() =~ /^B$/ break=never
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (PASS) [user_exists] () =~ // break=on-false
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
EXECUTE [depth=0] sofia/internal/587@vpbx-stpeters.bitco.co.za set(user_exists=false)
2020-12-15 11:23:19.367517 [DEBUG] mod_dptools.c:1672 SET sofia/internal/587@vpbx-stpeters.bitco.co.za [user_exists]=[false]
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
EXECUTE [depth=0] sofia/internal/587@vpbx-stpeters.bitco.co.za set(from_user_exists=true)
2020-12-15 11:23:19.387479 [DEBUG] mod_dptools.c:1672 SET sofia/internal/587@vpbx-stpeters.bitco.co.za [from_user_exists]=[true]
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za parsing [vpbx-stpeters.bitco.co.za->caller-details] continue=true
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (PASS) [caller-details] ${caller_destination}() =~ /^$/ break=never
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Action set(caller_destination=${destination_number}) INLINE
EXECUTE [depth=0] sofia/internal/587@vpbx-stpeters.bitco.co.za set(caller_destination=*08)
2020-12-15 11:23:19.387479 [DEBUG] mod_dptools.c:1672 SET sofia/internal/587@vpbx-stpeters.bitco.co.za [caller_destination]=[*08]
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Action set(caller_id_name=${caller_id_name}) INLINE
EXECUTE [depth=0] sofia/internal/587@vpbx-stpeters.bitco.co.za set(caller_id_name=587)
2020-12-15 11:23:19.387479 [DEBUG] mod_dptools.c:1672 SET sofia/internal/587@vpbx-stpeters.bitco.co.za [caller_id_name]=[587]
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Action set(caller_id_number=${caller_id_number})
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za parsing [vpbx-stpeters.bitco.co.za->call-direction] continue=true
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [call-direction] ${call_direction}() =~ /^(inbound|outbound|local)$/ break=never
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za ANTI-Action export(call_direction=local) INLINE
EXECUTE [depth=0] sofia/internal/587@vpbx-stpeters.bitco.co.za export(call_direction=local)
2020-12-15 11:23:19.387479 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [call_direction]=[local]
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za parsing [vpbx-stpeters.bitco.co.za->global-variables] continue=true
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (PASS) [global-variables] () =~ // break=on-false
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za parsing [vpbx-stpeters.bitco.co.za->domain-variables] continue=true
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (PASS) [domain-variables] () =~ // break=on-false
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Action export(origination_callee_id_name=${destination_number})
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za parsing [vpbx-stpeters.bitco.co.za->is_loopback] continue=true
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [is_loopback] ${is_follow_me_loopback}() =~ /true/ break=on-false
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za parsing [vpbx-stpeters.bitco.co.za->user_record] continue=true
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Action set(from_user_record=${user_data ${sip_from_user}@${sip_from_host} var user_record}) INLINE
EXECUTE [depth=0] sofia/internal/587@vpbx-stpeters.bitco.co.za set(from_user_record=)
2020-12-15 11:23:19.387479 [DEBUG] mod_dptools.c:1672 SET sofia/internal/587@vpbx-stpeters.bitco.co.za [from_user_record]=[UNDEF]
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za parsing [vpbx-stpeters.bitco.co.za->redial] continue=true
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [redial] destination_number(*08) =~ /^(redial|\*870)$/ break=on-true
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (PASS) [redial] () =~ // break=never
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za parsing [vpbx-stpeters.bitco.co.za->speed_dial] continue=false
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (PASS) [speed_dial] destination_number(*08) =~ /^\*0(.*)$/ break=on-false
Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Action lua(app.lua speed_dial 8)
2020-12-15 11:23:19.387479 [DEBUG] switch_core_state_machine.c:287 (sofia/internal/587@vpbx-stpeters.bitco.co.za) State Change CS_ROUTING -> CS_EXECUTE
2020-12-15 11:23:19.387479 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/587@vpbx-stpeters.bitco.co.za) State ROUTING going to sleep
2020-12-15 11:23:19.387479 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/587@vpbx-stpeters.bitco.co.za) Running State Change CS_EXECUTE (Cur 2 Tot 178)
2020-12-15 11:23:19.387479 [DEBUG] switch_core_state_machine.c:651 (sofia/internal/587@vpbx-stpeters.bitco.co.za) State EXECUTE
2020-12-15 11:23:19.387479 [DEBUG] mod_sofia.c:209 sofia/internal/587@vpbx-stpeters.bitco.co.za SOFIA EXECUTE
2020-12-15 11:23:19.387479 [DEBUG] switch_core_state_machine.c:329 sofia/internal/587@vpbx-stpeters.bitco.co.za Standard EXECUTE
EXECUTE [depth=0] sofia/internal/587@vpbx-stpeters.bitco.co.za set(caller_id_number=587)
2020-12-15 11:23:19.387479 [DEBUG] mod_dptools.c:1672 SET sofia/internal/587@vpbx-stpeters.bitco.co.za [caller_id_number]=[587]
EXECUTE [depth=0] sofia/internal/587@vpbx-stpeters.bitco.co.za set(RFC2822_DATE=Tue, 15 Dec 2020 11:23:19 +0200)
2020-12-15 11:23:19.387479 [DEBUG] mod_dptools.c:1672 SET sofia/internal/587@vpbx-stpeters.bitco.co.za [RFC2822_DATE]=[Tue, 15 Dec 2020 11:23:19 +0200]
EXECUTE [depth=0] sofia/internal/587@vpbx-stpeters.bitco.co.za export(origination_callee_id_name=*08)
2020-12-15 11:23:19.387479 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [origination_callee_id_name]=[*08]
EXECUTE [depth=0] sofia/internal/587@vpbx-stpeters.bitco.co.za hash(insert/vpbx-stpeters.bitco.co.za-last_dial/587/*08)
EXECUTE [depth=0] sofia/internal/587@vpbx-stpeters.bitco.co.za lua(app.lua speed_dial 8)
2020-12-15 11:23:19.387479 [WARNING] switch_cpp.cpp:1447 [app:dialplan:outbound:speed_dial] can not find number: 8 in domain: vpbx-stpeters.bitco.co.za
2020-12-15 11:23:19.387479 [DEBUG] switch_cpp.cpp:1191 sofia/internal/587@vpbx-stpeters.bitco.co.za destroy/unlink session from object
2020-12-15 11:23:19.387479 [NOTICE] switch_core_state_machine.c:386 sofia/internal/587@vpbx-stpeters.bitco.co.za has executed the last dialplan instruction, hanging up.
2020-12-15 11:23:19.387479 [NOTICE] switch_core_state_machine.c:388 Hangup sofia/internal/587@vpbx-stpeters.bitco.co.za [CS_EXECUTE] [NORMAL_CLEARING]
2020-12-15 11:23:19.387479 [DEBUG] switch_core_state_machine.c:651 (sofia/internal/587@vpbx-stpeters.bitco.co.za) State EXECUTE going to sleep
2020-12-15 11:23:19.387479 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/587@vpbx-stpeters.bitco.co.za) Running State Change CS_HANGUP (Cur 2 Tot 178)
2020-12-15 11:23:19.387479 [DEBUG] switch_core_state_machine.c:848 (sofia/internal/587@vpbx-stpeters.bitco.co.za) Callstate Change RINGING -> HANGUP
2020-12-15 11:23:19.387479 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/587@vpbx-stpeters.bitco.co.za) State HANGUP
2020-12-15 11:23:19.387479 [DEBUG] mod_sofia.c:453 Channel sofia/internal/587@vpbx-stpeters.bitco.co.za hanging up, cause: NORMAL_CLEARING
2020-12-15 11:23:19.387479 [DEBUG] mod_sofia.c:598 Responding to INVITE with: 480
2020-12-15 11:23:19.387479 [DEBUG] switch_core_state_machine.c:60 sofia/internal/587@vpbx-stpeters.bitco.co.za Standard HANGUP, cause: NORMAL_CLEARING
2020-12-15 11:23:19.387479 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/587@vpbx-stpeters.bitco.co.za) State HANGUP going to sleep
2020-12-15 11:23:19.387479 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/587@vpbx-stpeters.bitco.co.za) State Change CS_HANGUP -> CS_REPORTING
2020-12-15 11:23:19.387479 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/587@vpbx-stpeters.bitco.co.za) Running State Change CS_REPORTING (Cur 2 Tot 178)
2020-12-15 11:23:19.387479 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/587@vpbx-stpeters.bitco.co.za) State REPORTING
2020-12-15 11:23:19.427487 [DEBUG] switch_core_state_machine.c:174 sofia/internal/587@vpbx-stpeters.bitco.co.za Standard REPORTING, cause: NORMAL_CLEARING
2020-12-15 11:23:19.427487 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/587@vpbx-stpeters.bitco.co.za) State REPORTING going to sleep
2020-12-15 11:23:19.427487 [DEBUG] switch_core_state_machine.c:611 (sofia/internal/587@vpbx-stpeters.bitco.co.za) State Change CS_REPORTING -> CS_DESTROY
2020-12-15 11:23:19.427487 [DEBUG] switch_core_session.c:1726 Session 178 (sofia/internal/587@vpbx-stpeters.bitco.co.za) Locked, Waiting on external entities
2020-12-15 11:23:19.427487 [NOTICE] switch_core_session.c:1744 Session 178 (sofia/internal/587@vpbx-stpeters.bitco.co.za) Ended
2020-12-15 11:23:19.427487 [NOTICE] switch_core_session.c:1748 Close Channel sofia/internal/587@vpbx-stpeters.bitco.co.za [CS_DESTROY]
2020-12-15 11:23:19.427487 [DEBUG] switch_core_state_machine.c:739 (sofia/internal/587@vpbx-stpeters.bitco.co.za) Running State Change CS_DESTROY (Cur 1 Tot 178)
2020-12-15 11:23:19.427487 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/587@vpbx-stpeters.bitco.co.za) State DESTROY
2020-12-15 11:23:19.427487 [DEBUG] mod_sofia.c:364 sofia/internal/587@vpbx-stpeters.bitco.co.za SOFIA DESTROY
2020-12-15 11:23:19.427487 [DEBUG] switch_core_state_machine.c:181 sofia/internal/587@vpbx-stpeters.bitco.co.za Standard DESTROY
2020-12-15 11:23:19.427487 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/587@vpbx-stpeters.bitco.co.za) State DESTROY going to sleep
2020-12-15 11:23:21.247523 [DEBUG] switch_ivr_menu.c:425 digits '1'
2020-12-15 11:23:21.247523 [DEBUG] switch_ivr_menu.c:580 IVR action on menu '4680ddce-d7d9-4068-81f8-5b3414b852a4' matched '1' param 'transfer 202 XML vpbx-stpeters.bitco.co.za'
2020-12-15 11:23:21.247523 [DEBUG] switch_ivr_menu.c:584 switch_ivr_menu_execute todo=[2]
EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 transfer(202 XML vpbx-stpeters.bitco.co.za)
2020-12-15 11:23:21.247523 [DEBUG] switch_ivr.c:2243 (sofia/external/0827080139@41.79.80.10) State Change CS_EXECUTE -> CS_ROUTING
2020-12-15 11:23:21.247523 [NOTICE] switch_ivr.c:2250 Transfer sofia/external/0827080139@41.79.80.10 to XML[202@vpbx-stpeters.bitco.co.za]
2020-12-15 11:23:21.247523 [DEBUG] switch_ivr_menu.c:562 action regex [1] [/^(\d{2,11})$/] [0]
2020-12-15 11:23:21.247523 [DEBUG] switch_ivr_menu.c:562 action regex [1] [/^(\d{2,11})$/] [0]
2020-12-15 11:23:21.247523 [DEBUG] switch_ivr_menu.c:562 action regex [1] [/^(\d{2,11})$/] [0]
2020-12-15 11:23:21.247523 [DEBUG] switch_ivr_menu.c:676 exit-sound '(null)'
2020-12-15 11:23:21.247523 [DEBUG] switch_core_state_machine.c:651 (sofia/external/0827080139@41.79.80.10) State EXECUTE going to sleep
2020-12-15 11:23:21.247523 [DEBUG] switch_core_state_machine.c:585 (sofia/external/0827080139@41.79.80.10) Running State Change CS_ROUTING (Cur 1 Tot 178)
2020-12-15 11:23:21.247523 [DEBUG] switch_channel.c:2332 (sofia/external/0827080139@41.79.80.10) Callstate Change ACTIVE -> RINGING
2020-12-15 11:23:21.247523 [DEBUG] switch_core_state_machine.c:644 (sofia/external/0827080139@41.79.80.10) State ROUTING
2020-12-15 11:23:21.247523 [DEBUG] mod_sofia.c:154 sofia/external/0827080139@41.79.80.10 SOFIA ROUTING
2020-12-15 11:23:21.247523 [DEBUG] switch_core_state_machine.c:236 sofia/external/0827080139@41.79.80.10 Standard ROUTING
2020-12-15 11:23:21.247523 [INFO] mod_dialplan_xml.c:637 Processing +27827080139 <0827080139>->202 in context vpbx-stpeters.bitco.co.za
Dialplan: sofia/external/0827080139@41.79.80.10 parsing [vpbx-stpeters.bitco.co.za->user_exists] continue=true
Dialplan: sofia/external/0827080139@41.79.80.10 Regex (FAIL) [user_exists] ${loopback_leg}() =~ /^B$/ break=never
Dialplan: sofia/external/0827080139@41.79.80.10 Regex (PASS) [user_exists] () =~ // break=on-false
Dialplan: sofia/external/0827080139@41.79.80.10 Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(user_exists=true)
2020-12-15 11:23:21.267483 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [user_exists]=[true]
Dialplan: sofia/external/0827080139@41.79.80.10 Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(from_user_exists=false)
2020-12-15 11:23:21.267483 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [from_user_exists]=[false]
Dialplan: sofia/external/0827080139@41.79.80.10 Regex (PASS) [user_exists] ${user_exists}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/0827080139@41.79.80.10 Action set(extension_uuid=${user_data ${destination_number}@${domain_name} var extension_uuid}) INLINE
EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(extension_uuid=d4c3d40d-5d83-45f5-b1c3-c7fb4da2f0be)
2020-12-15 11:23:21.267483 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [extension_uuid]=[d4c3d40d-5d83-45f5-b1c3-c7fb4da2f0be]
Dialplan: sofia/external/0827080139@41.79.80.10 Action set(hold_music=${user_data ${destination_number}@${domain_name} var hold_music}) INLINE
EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(hold_music=local_stream://vpbx-stpeters.bitco.co.za/Custom)
2020-12-15 11:23:21.267483 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [hold_music]=[local_stream://vpbx-stpeters.bitco.co.za/Custom]
Dialplan: sofia/external/0827080139@41.79.80.10 Action set(forward_all_enabled=${user_data ${destination_number}@${domain_name} var forward_all_enabled}) INLINE
EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(forward_all_enabled=false)
2020-12-15 11:23:21.267483 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [forward_all_enabled]=[false]
Dialplan: sofia/external/0827080139@41.79.80.10 Action set(forward_all_destination=${user_data ${destination_number}@${domain_name} var forward_all_destination}) INLINE
EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(forward_all_destination=)
2020-12-15 11:23:21.287590 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [forward_all_destination]=[UNDEF]
Dialplan: sofia/external/0827080139@41.79.80.10 Action set(forward_busy_enabled=${user_data ${destination_number}@${domain_name} var forward_busy_enabled}) INLINE
EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(forward_busy_enabled=false)
2020-12-15 11:23:21.287590 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [forward_busy_enabled]=[false]
Dialplan: sofia/external/0827080139@41.79.80.10 Action set(forward_busy_destination=${user_data ${destination_number}@${domain_name} var forward_busy_destination}) INLINE
EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(forward_busy_destination=)
2020-12-15 11:23:21.287590 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [forward_busy_destination]=[UNDEF]
Dialplan: sofia/external/0827080139@41.79.80.10 Action set(forward_no_answer_enabled=${user_data ${destination_number}@${domain_name} var forward_no_answer_enabled}) INLINE
EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(forward_no_answer_enabled=false)
2020-12-15 11:23:21.287590 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [forward_no_answer_enabled]=[false]
Dialplan: sofia/external/0827080139@41.79.80.10 Action set(forward_no_answer_destination=${user_data ${destination_number}@${domain_name} var forward_no_answer_destination}) INLINE
EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(forward_no_answer_destination=)
2020-12-15 11:23:21.287590 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [forward_no_answer_destination]=[UNDEF]
Dialplan: sofia/external/0827080139@41.79.80.10 Action set(forward_user_not_registered_enabled=${user_data ${destination_number}@${domain_name} var forward_user_not_registered_enabled}) INLINE
EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(forward_user_not_registered_enabled=false)
2020-12-15 11:23:21.287590 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [forward_user_not_registered_enabled]=[false]
Dialplan: sofia/external/0827080139@41.79.80.10 Action set(forward_user_not_registered_destination=${user_data ${destination_number}@${domain_name} var forward_user_not_registered_destination}) INLINE
EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(forward_user_not_registered_destination=)
2020-12-15 11:23:21.287590 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [forward_user_not_registered_destination]=[UNDEF]
Dialplan: sofia/external/0827080139@41.79.80.10 Action set(forward_all_enabled=${user_data ${destination_number}@${domain_name} var forward_all_enabled}) INLINE
EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(forward_all_enabled=false)
2020-12-15 11:23:21.287590 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [forward_all_enabled]=[false]
Dialplan: sofia/external/0827080139@41.79.80.10 Action set(follow_me_enabled=${user_data ${destination_number}@${domain_name} var follow_me_enabled}) INLINE
EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(follow_me_enabled=true)
2020-12-15 11:23:21.287590 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [follow_me_enabled]=[true]
Dialplan: sofia/external/0827080139@41.79.80.10 Action set(do_not_disturb=${user_data ${destination_number}@${domain_name} var do_not_disturb}) INLINE
EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(do_not_disturb=false)
2020-12-15 11:23:21.287590 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [do_not_disturb]=[false]
Dialplan: sofia/external/0827080139@41.79.80.10 Action set(call_timeout=${user_data ${destination_number}@${domain_name} var call_timeout}) INLINE
EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(call_timeout=30)
2020-12-15 11:23:21.287590 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [call_timeout]=[30]
Dialplan: sofia/external/0827080139@41.79.80.10 Action set(missed_call_app=${user_data ${destination_number}@${domain_name} var missed_call_app}) INLINE
EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(missed_call_app=)
2020-12-15 11:23:21.287590 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [missed_call_app]=[UNDEF]
Dialplan: sofia/external/0827080139@41.79.80.10 Action set(missed_call_data=${user_data ${destination_number}@${domain_name} var missed_call_data}) INLINE
EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(missed_call_data=)
2020-12-15 11:23:21.287590 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [missed_call_data]=[UNDEF]
Dialplan: sofia/external/0827080139@41.79.80.10 Action set(toll_allow=${user_data ${destination_number}@${domain_name} var toll_allow}) INLINE