1. 2020-12-15 11:23:19.247516 [DEBUG] switch_rtp.c:7967 RTP RECV DTMF 1:960
2. 2020-12-15 11:23:19.247516 [INFO] switch_channel.c:522 RECV DTMF 1:960
3. 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
4. 2020-12-15 11:23:19.247516 [DEBUG] switch_ivr_menu.c:378 waiting for 4/5 digits t/o 2000
5. 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]
6. 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)
7. 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
8. 2020-12-15 11:23:19.347517 [DEBUG] sofia.c:10373 verifying acl "domains" for ip/port 41.79.81.110:0.
9. 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
10. 2020-12-15 11:23:19.347517 [DEBUG] switch_core_state_machine.c:604 (sofia/internal/587@vpbx-stpeters.bitco.co.za) State NEW
11. 2020-12-15 11:23:19.347517 [DEBUG] sofia.c:2434 detaching session 421c0b0a-10ae-42cf-9839-4f62371a0888
12. 2020-12-15 11:23:19.347517 [DEBUG] sofia.c:2544 Re-attaching to session 421c0b0a-10ae-42cf-9839-4f62371a0888
13. 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
14. 2020-12-15 11:23:19.367517 [DEBUG] sofia.c:10373 verifying acl "domains" for ip/port 41.79.81.110:0.
15. 2020-12-15 11:23:19.367517 [DEBUG] sofia.c:7325 Channel sofia/internal/587@vpbx-stpeters.bitco.co.za entering state [received][100]
16. 2020-12-15 11:23:19.367517 [DEBUG] sofia.c:7335 Remote SDP:
17. v=0
18. o=- 3817020199 3817020199 IN IP4 41.79.81.110
19. s=pjmedia
20. b=AS:29
21. t=0 0
22. a=X-nat:0
23. m=audio 32274 RTP/AVP 18 101
24. c=IN IP4 41.79.81.110
25. b=TIAS:11800
26. a=rtpmap:18 G729/8000
27. a=rtpmap:101 telephone-event/8000
28. a=fmtp:101 0-16
29. a=rtcp:32275 IN IP4 41.79.81.110
30. a=ssrc:578639085 cname:028b1469740d661b
31.  
32. 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]
33. 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
34. 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]
35. 2020-12-15 11:23:19.367517 [DEBUG] switch_core_media.c:5508 Set telephone-event payload to 101@8000
36. 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
37. 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
38. 2020-12-15 11:23:19.367517 [DEBUG] switch_core_media.c:5851 Set telephone-event payload to 101@8000
39. 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
40. 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
41. 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)
42. 2020-12-15 11:23:19.367517 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/587@vpbx-stpeters.bitco.co.za) State INIT
43. 2020-12-15 11:23:19.367517 [DEBUG] mod_sofia.c:93 sofia/internal/587@vpbx-stpeters.bitco.co.za SOFIA INIT
44. 2020-12-15 11:23:19.367517 [DEBUG] switch_core_state_machine.c:40 sofia/internal/587@vpbx-stpeters.bitco.co.za Standard INIT
45. 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
46. 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
47. 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)
48. 2020-12-15 11:23:19.367517 [DEBUG] switch_channel.c:2332 (sofia/internal/587@vpbx-stpeters.bitco.co.za) Callstate Change DOWN -> RINGING
49. 2020-12-15 11:23:19.367517 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/587@vpbx-stpeters.bitco.co.za) State ROUTING
50. 2020-12-15 11:23:19.367517 [DEBUG] mod_sofia.c:154 sofia/internal/587@vpbx-stpeters.bitco.co.za SOFIA ROUTING
51. 2020-12-15 11:23:19.367517 [DEBUG] switch_core_state_machine.c:236 sofia/internal/587@vpbx-stpeters.bitco.co.za Standard ROUTING
52. 2020-12-15 11:23:19.367517 [INFO] mod_dialplan_xml.c:637 Processing 587 <587>->*08 in context vpbx-stpeters.bitco.co.za
53. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za parsing [vpbx-stpeters.bitco.co.za->user_exists] continue=true
54. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_exists] ${loopback_leg}() =~ /^B$/ break=never
55. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (PASS) [user_exists] () =~ // break=on-false
56. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
57. EXECUTE [depth=0] sofia/internal/587@vpbx-stpeters.bitco.co.za set(user_exists=false)
58. 2020-12-15 11:23:19.367517 [DEBUG] mod_dptools.c:1672 SET sofia/internal/587@vpbx-stpeters.bitco.co.za [user_exists]=[false]
59. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
60. EXECUTE [depth=0] sofia/internal/587@vpbx-stpeters.bitco.co.za set(from_user_exists=true)
61. 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]
62. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
63. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za parsing [vpbx-stpeters.bitco.co.za->caller-details] continue=true
64. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (PASS) [caller-details] ${caller_destination}() =~ /^$/ break=never
65. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Action set(caller_destination=${destination_number}) INLINE
66. EXECUTE [depth=0] sofia/internal/587@vpbx-stpeters.bitco.co.za set(caller_destination=*08)
67. 2020-12-15 11:23:19.387479 [DEBUG] mod_dptools.c:1672 SET sofia/internal/587@vpbx-stpeters.bitco.co.za [caller_destination]=[*08]
68. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Action set(caller_id_name=${caller_id_name}) INLINE
69. EXECUTE [depth=0] sofia/internal/587@vpbx-stpeters.bitco.co.za set(caller_id_name=587)
70. 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]
71. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Action set(caller_id_number=${caller_id_number})
72. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za parsing [vpbx-stpeters.bitco.co.za->call-direction] continue=true
73. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [call-direction] ${call_direction}() =~ /^(inbound|outbound|local)$/ break=never
74. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za ANTI-Action export(call_direction=local) INLINE
75. EXECUTE [depth=0] sofia/internal/587@vpbx-stpeters.bitco.co.za export(call_direction=local)
76. 2020-12-15 11:23:19.387479 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [call_direction]=[local]
77. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za parsing [vpbx-stpeters.bitco.co.za->global-variables] continue=true
78. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (PASS) [global-variables] () =~ // break=on-false
79. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
80. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za parsing [vpbx-stpeters.bitco.co.za->domain-variables] continue=true
81. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (PASS) [domain-variables] () =~ // break=on-false
82. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Action export(origination_callee_id_name=${destination_number})
83. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za parsing [vpbx-stpeters.bitco.co.za->is_loopback] continue=true
84. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [is_loopback] ${is_follow_me_loopback}() =~ /true/ break=on-false
85. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za parsing [vpbx-stpeters.bitco.co.za->user_record] continue=true
86. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
87. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
88. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
89. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
90. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
91. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
92. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
93. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
94. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
95. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
96. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
97. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
98. 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
99. EXECUTE [depth=0] sofia/internal/587@vpbx-stpeters.bitco.co.za set(from_user_record=)
100. 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]
101. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
102. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never
103. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
104. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
105. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never
106. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
107. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
108. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never
109. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
110. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
111. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never
112. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false
113. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za parsing [vpbx-stpeters.bitco.co.za->redial] continue=true
114. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (FAIL) [redial] destination_number(*08) =~ /^(redial|\*870)$/ break=on-true
115. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (PASS) [redial] () =~ // break=never
116. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
117. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za parsing [vpbx-stpeters.bitco.co.za->speed_dial] continue=false
118. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Regex (PASS) [speed_dial] destination_number(*08) =~ /^\*0(.*)$/ break=on-false
119. Dialplan: sofia/internal/587@vpbx-stpeters.bitco.co.za Action lua(app.lua speed_dial 8)
120. 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
121. 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
122. 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)
123. 2020-12-15 11:23:19.387479 [DEBUG] switch_core_state_machine.c:651 (sofia/internal/587@vpbx-stpeters.bitco.co.za) State EXECUTE
124. 2020-12-15 11:23:19.387479 [DEBUG] mod_sofia.c:209 sofia/internal/587@vpbx-stpeters.bitco.co.za SOFIA EXECUTE
125. 2020-12-15 11:23:19.387479 [DEBUG] switch_core_state_machine.c:329 sofia/internal/587@vpbx-stpeters.bitco.co.za Standard EXECUTE
126. EXECUTE [depth=0] sofia/internal/587@vpbx-stpeters.bitco.co.za set(caller_id_number=587)
127. 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]
128. EXECUTE [depth=0] sofia/internal/587@vpbx-stpeters.bitco.co.za set(RFC2822_DATE=Tue, 15 Dec 2020 11:23:19 +0200)
129. 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]
130. EXECUTE [depth=0] sofia/internal/587@vpbx-stpeters.bitco.co.za export(origination_callee_id_name=*08)
131. 2020-12-15 11:23:19.387479 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [origination_callee_id_name]=[*08]
132. EXECUTE [depth=0] sofia/internal/587@vpbx-stpeters.bitco.co.za hash(insert/vpbx-stpeters.bitco.co.za-last_dial/587/*08)
133. EXECUTE [depth=0] sofia/internal/587@vpbx-stpeters.bitco.co.za lua(app.lua speed_dial 8)
134. 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
135. 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
136. 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.
137. 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]
138. 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
139. 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)
140. 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
141. 2020-12-15 11:23:19.387479 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/587@vpbx-stpeters.bitco.co.za) State HANGUP
142. 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
143. 2020-12-15 11:23:19.387479 [DEBUG] mod_sofia.c:598 Responding to INVITE with: 480
144. 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
145. 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
146. 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
147. 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)
148. 2020-12-15 11:23:19.387479 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/587@vpbx-stpeters.bitco.co.za) State REPORTING
149. 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
150. 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
151. 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
152. 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
153. 2020-12-15 11:23:19.427487 [NOTICE] switch_core_session.c:1744 Session 178 (sofia/internal/587@vpbx-stpeters.bitco.co.za) Ended
154. 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]
155. 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)
156. 2020-12-15 11:23:19.427487 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/587@vpbx-stpeters.bitco.co.za) State DESTROY
157. 2020-12-15 11:23:19.427487 [DEBUG] mod_sofia.c:364 sofia/internal/587@vpbx-stpeters.bitco.co.za SOFIA DESTROY
158. 2020-12-15 11:23:19.427487 [DEBUG] switch_core_state_machine.c:181 sofia/internal/587@vpbx-stpeters.bitco.co.za Standard DESTROY
159. 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
160. 2020-12-15 11:23:21.247523 [DEBUG] switch_ivr_menu.c:425 digits '1'
161. 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'
162. 2020-12-15 11:23:21.247523 [DEBUG] switch_ivr_menu.c:584 switch_ivr_menu_execute todo=[2]
163. EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 transfer(202 XML vpbx-stpeters.bitco.co.za)
164. 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
165. 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]
166. 2020-12-15 11:23:21.247523 [DEBUG] switch_ivr_menu.c:562 action regex [1] [/^(\d{2,11})$/] [0]
167. 2020-12-15 11:23:21.247523 [DEBUG] switch_ivr_menu.c:562 action regex [1] [/^(\d{2,11})$/] [0]
168. 2020-12-15 11:23:21.247523 [DEBUG] switch_ivr_menu.c:562 action regex [1] [/^(\d{2,11})$/] [0]
169. 2020-12-15 11:23:21.247523 [DEBUG] switch_ivr_menu.c:676 exit-sound '(null)'
170. 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
171. 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)
172. 2020-12-15 11:23:21.247523 [DEBUG] switch_channel.c:2332 (sofia/external/0827080139@41.79.80.10) Callstate Change ACTIVE -> RINGING
173. 2020-12-15 11:23:21.247523 [DEBUG] switch_core_state_machine.c:644 (sofia/external/0827080139@41.79.80.10) State ROUTING
174. 2020-12-15 11:23:21.247523 [DEBUG] mod_sofia.c:154 sofia/external/0827080139@41.79.80.10 SOFIA ROUTING
175. 2020-12-15 11:23:21.247523 [DEBUG] switch_core_state_machine.c:236 sofia/external/0827080139@41.79.80.10 Standard ROUTING
176. 2020-12-15 11:23:21.247523 [INFO] mod_dialplan_xml.c:637 Processing +27827080139 <0827080139>->202 in context vpbx-stpeters.bitco.co.za
177. Dialplan: sofia/external/0827080139@41.79.80.10 parsing [vpbx-stpeters.bitco.co.za->user_exists] continue=true
178. Dialplan: sofia/external/0827080139@41.79.80.10 Regex (FAIL) [user_exists] ${loopback_leg}() =~ /^B$/ break=never
179. Dialplan: sofia/external/0827080139@41.79.80.10 Regex (PASS) [user_exists] () =~ // break=on-false
180. Dialplan: sofia/external/0827080139@41.79.80.10 Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
181. EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(user_exists=true)
182. 2020-12-15 11:23:21.267483 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [user_exists]=[true]
183. Dialplan: sofia/external/0827080139@41.79.80.10 Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
184. EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(from_user_exists=false)
185. 2020-12-15 11:23:21.267483 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [from_user_exists]=[false]
186. Dialplan: sofia/external/0827080139@41.79.80.10 Regex (PASS) [user_exists] ${user_exists}(true) =~ /^true$/ break=on-false
187. Dialplan: sofia/external/0827080139@41.79.80.10 Action set(extension_uuid=${user_data ${destination_number}@${domain_name} var extension_uuid}) INLINE
188. EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(extension_uuid=d4c3d40d-5d83-45f5-b1c3-c7fb4da2f0be)
189. 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]
190. Dialplan: sofia/external/0827080139@41.79.80.10 Action set(hold_music=${user_data ${destination_number}@${domain_name} var hold_music}) INLINE
191. EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(hold_music=local_stream://vpbx-stpeters.bitco.co.za/Custom)
192. 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]
193. Dialplan: sofia/external/0827080139@41.79.80.10 Action set(forward_all_enabled=${user_data ${destination_number}@${domain_name} var forward_all_enabled}) INLINE
194. EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(forward_all_enabled=false)
195. 2020-12-15 11:23:21.267483 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [forward_all_enabled]=[false]
196. Dialplan: sofia/external/0827080139@41.79.80.10 Action set(forward_all_destination=${user_data ${destination_number}@${domain_name} var forward_all_destination}) INLINE
197. EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(forward_all_destination=)
198. 2020-12-15 11:23:21.287590 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [forward_all_destination]=[UNDEF]
199. Dialplan: sofia/external/0827080139@41.79.80.10 Action set(forward_busy_enabled=${user_data ${destination_number}@${domain_name} var forward_busy_enabled}) INLINE
200. EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(forward_busy_enabled=false)
201. 2020-12-15 11:23:21.287590 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [forward_busy_enabled]=[false]
202. Dialplan: sofia/external/0827080139@41.79.80.10 Action set(forward_busy_destination=${user_data ${destination_number}@${domain_name} var forward_busy_destination}) INLINE
203. EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(forward_busy_destination=)
204. 2020-12-15 11:23:21.287590 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [forward_busy_destination]=[UNDEF]
205. 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
206. EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(forward_no_answer_enabled=false)
207. 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]
208. 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
209. EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(forward_no_answer_destination=)
210. 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]
211. 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
212. EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(forward_user_not_registered_enabled=false)
213. 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]
214. 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
215. EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(forward_user_not_registered_destination=)
216. 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]
217. Dialplan: sofia/external/0827080139@41.79.80.10 Action set(forward_all_enabled=${user_data ${destination_number}@${domain_name} var forward_all_enabled}) INLINE
218. EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(forward_all_enabled=false)
219. 2020-12-15 11:23:21.287590 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [forward_all_enabled]=[false]
220. Dialplan: sofia/external/0827080139@41.79.80.10 Action set(follow_me_enabled=${user_data ${destination_number}@${domain_name} var follow_me_enabled}) INLINE
221. EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(follow_me_enabled=true)
222. 2020-12-15 11:23:21.287590 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [follow_me_enabled]=[true]
223. Dialplan: sofia/external/0827080139@41.79.80.10 Action set(do_not_disturb=${user_data ${destination_number}@${domain_name} var do_not_disturb}) INLINE
224. EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(do_not_disturb=false)
225. 2020-12-15 11:23:21.287590 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [do_not_disturb]=[false]
226. Dialplan: sofia/external/0827080139@41.79.80.10 Action set(call_timeout=${user_data ${destination_number}@${domain_name} var call_timeout}) INLINE
227. EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(call_timeout=30)
228. 2020-12-15 11:23:21.287590 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [call_timeout]=[30]
229. Dialplan: sofia/external/0827080139@41.79.80.10 Action set(missed_call_app=${user_data ${destination_number}@${domain_name} var missed_call_app}) INLINE
230. EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(missed_call_app=)
231. 2020-12-15 11:23:21.287590 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [missed_call_app]=[UNDEF]
232. Dialplan: sofia/external/0827080139@41.79.80.10 Action set(missed_call_data=${user_data ${destination_number}@${domain_name} var missed_call_data}) INLINE
233. EXECUTE [depth=0] sofia/external/0827080139@41.79.80.10 set(missed_call_data=)
234. 2020-12-15 11:23:21.287590 [DEBUG] mod_dptools.c:1672 SET sofia/external/0827080139@41.79.80.10 [missed_call_data]=[UNDEF]
235. Dialplan: sofia/external/0827080139@41.79.80.10 Action set(toll_allow=${user_data ${destination_number}@${domain_name} var toll_allow}) INLINE
236.