1. 2019-11-12 15:44:51.159712 [NOTICE] switch_channel.c:1114 New Channel sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 [99a68ea8-1458-45db-b07c-f6e29e1baff9]
2. 2019-11-12 15:44:51.159712 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060) Running State Change CS_NEW (Cur 39 Tot 43413)
3. 2019-11-12 15:44:51.159712 [DEBUG] sofia.c:10164 sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 receiving invite from 41.79.81.110:1564 version: 1.8.7 -8-6047ebddfc 64bit
4. 2019-11-12 15:44:51.159712 [DEBUG] sofia.c:10260 verifying acl "domains" for ip/port 41.79.81.110:0.
5. 2019-11-12 15:44:51.159712 [WARNING] sofia_reg.c:1798 SIP auth challenge (INVITE) on sofia profile 'internal' for [*87201@vpbx-stockbrockers-jhb.bitcovoice.com] from ip 41.79.81.110
6. 2019-11-12 15:44:51.159712 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060) State NEW
7. 2019-11-12 15:44:51.159712 [DEBUG] sofia.c:2413 detaching session 99a68ea8-1458-45db-b07c-f6e29e1baff9
8. 2019-11-12 15:44:51.179728 [DEBUG] sofia.c:2522 Re-attaching to session 99a68ea8-1458-45db-b07c-f6e29e1baff9
9. 2019-11-12 15:44:51.179728 [DEBUG] sofia.c:10164 sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 receiving invite from 41.79.81.110:1564 version: 1.8.7 -8-6047ebddfc 64bit
10. 2019-11-12 15:44:51.179728 [DEBUG] sofia.c:10260 verifying acl "domains" for ip/port 41.79.81.110:0.
11. 2019-11-12 15:44:51.179728 [WARNING] sofia_reg.c:1798 SIP auth challenge (REGISTER) on sofia profile 'internal' for [2033@vpbx-linvar-sa.bitcovoice.com] from ip 196.50.253.234
12. 2019-11-12 15:44:51.199727 [DEBUG] sofia.c:11370 Setting NAT mode based on via received
13. 2019-11-12 15:44:51.199727 [DEBUG] sofia.c:7323 Channel sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 entering state [received][100]
14. 2019-11-12 15:44:51.199727 [DEBUG] sofia.c:7333 Remote SDP:
15. v=0
16. o=- 20079 20079 IN IP4 192.168.96.93
17. s=SDP data
18. c=IN IP4 192.168.96.93
19. t=0 0
20. m=audio 12356 RTP/AVP 18 101
21. a=rtpmap:18 G729/8000
22. a=fmtp:18 annexb=no
23. a=rtpmap:101 telephone-event/8000
24. a=fmtp:101 0-15
25. a=ptime:20
26.  
27. 2019-11-12 15:44:51.199727 [DEBUG] switch_core_media.c:5511 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
28. 2019-11-12 15:44:51.199727 [DEBUG] switch_core_media.c:5566 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
29. 2019-11-12 15:44:51.199727 [DEBUG] switch_core_media.c:5511 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
30. 2019-11-12 15:44:51.199727 [DEBUG] switch_core_media.c:5427 Set telephone-event payload to 101@8000
31. 2019-11-12 15:44:51.199727 [DEBUG] switch_core_media.c:3781 Set Codec sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 G729/8000 20 ms 160 samples 8000 bits 1 channels
32. 2019-11-12 15:44:51.199727 [DEBUG] switch_core_codec.c:111 sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 Original read codec set to G729:18
33. 2019-11-12 15:44:51.199727 [DEBUG] switch_core_media.c:5770 Set telephone-event payload to 101@8000
34. 2019-11-12 15:44:51.199727 [DEBUG] switch_core_media.c:5828 sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 Set 2833 dtmf send payload to 101 recv payload to 101
35. 2019-11-12 15:44:51.199727 [DEBUG] sofia.c:7748 (sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060) State Change CS_NEW -> CS_INIT
36. 2019-11-12 15:44:51.199727 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060) Running State Change CS_INIT (Cur 39 Tot 43413)
37. 2019-11-12 15:44:51.199727 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060) State INIT
38. 2019-11-12 15:44:51.199727 [DEBUG] mod_sofia.c:93 sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 SOFIA INIT
39. 2019-11-12 15:44:51.199727 [DEBUG] switch_core_state_machine.c:40 sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 Standard INIT
40. 2019-11-12 15:44:51.199727 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060) State Change CS_INIT -> CS_ROUTING
41. 2019-11-12 15:44:51.199727 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060) State INIT going to sleep
42. 2019-11-12 15:44:51.199727 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060) Running State Change CS_ROUTING (Cur 39 Tot 43413)
43. 2019-11-12 15:44:51.199727 [DEBUG] switch_channel.c:2293 (sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060) Callstate Change DOWN -> RINGING
44. 2019-11-12 15:44:51.199727 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060) State ROUTING
45. 2019-11-12 15:44:51.199727 [DEBUG] mod_sofia.c:154 sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 SOFIA ROUTING
46. 2019-11-12 15:44:51.199727 [DEBUG] switch_core_state_machine.c:236 sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 Standard ROUTING
47. 2019-11-12 15:44:51.199727 [INFO] mod_dialplan_xml.c:637 Processing 4000 <4000>->*87201 in context vpbx-stockbrockers-jhb.bitcovoice.com
48. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 parsing [vpbx-stockbrockers-jhb.bitcovoice.com->user_exists] continue=true
49. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 Regex (PASS) [user_exists] () =~ // break=on-false
50. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
51. EXECUTE [depth=0] sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 set(user_exists=false)
52. 2019-11-12 15:44:51.199727 [DEBUG] mod_dptools.c:1615 SET sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 [user_exists]=[false]
53. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
54. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 parsing [vpbx-stockbrockers-jhb.bitcovoice.com->is_loopback] continue=true
55. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 Regex (FAIL) [is_loopback] ${is_follow_me_loopback}() =~ /true/ break=on-false
56. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 parsing [vpbx-stockbrockers-jhb.bitcovoice.com->bitco.10d] continue=false
57. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 Regex (PASS) [bitco.10d] ${user_exists}(false) =~ /false/ break=on-false
58. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 Regex (PASS) [bitco.10d] ${toll_allow}(nat) =~ /nat/ break=on-false
59. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 Regex (FAIL) [bitco.10d] destination_number(*87201) =~ /^(\d{10})$/ break=on-false
60. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 parsing [vpbx-stockbrockers-jhb.bitcovoice.com->bitco.International] continue=false
61. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 Regex (PASS) [bitco.International] ${user_exists}(false) =~ /false/ break=on-false
62. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 Regex (FAIL) [bitco.International] ${toll_allow}(nat) =~ /int/ break=on-false
63. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 parsing [vpbx-stockbrockers-jhb.bitcovoice.com->Office Hrs] continue=false
64. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 Regex (FAIL) [Office Hrs] destination_number(*87201) =~ /^60$/ break=on-false
65. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 parsing [vpbx-stockbrockers-jhb.bitcovoice.com->ring group] continue=
66. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 Regex (FAIL) [ring group] destination_number(*87201) =~ /^50$/ break=on-false
67. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 parsing [vpbx-stockbrockers-jhb.bitcovoice.com->After-Hrs] continue=false
68. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 Regex (FAIL) [After-Hrs] destination_number(*87201) =~ /^61$/ break=on-false
69. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 parsing [vpbx-stockbrockers-jhb.bitcovoice.com->ring group] continue=
70. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 Regex (FAIL) [ring group] destination_number(*87201) =~ /^51$/ break=on-false
71. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 parsing [vpbx-stockbrockers-jhb.bitcovoice.com->intercept-ext-polycom] continue=false
72. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 Regex (FAIL) [intercept-ext-polycom] destination_number(*87201) =~ /^\*97(\d+)$/ break=on-false
73. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 parsing [vpbx-stockbrockers-jhb.bitcovoice.com->TC 01] continue=true
74. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 Regex (FAIL) [TC 01] destination_number(*87201) =~ /^70$/ break=on-false
75. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 parsing [vpbx-stockbrockers-jhb.bitcovoice.com->extension-to-voicemail] continue=false
76. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 Regex (FAIL) [extension-to-voicemail] ${user_exists}(false) =~ /^true$/ break=on-false
77. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 parsing [vpbx-stockbrockers-jhb.bitcovoice.com->follow-me-destinations] continue=false
78. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 Regex (FAIL) [follow-me-destinations] ${user_exists}(false) =~ /^true$/ break=on-false
79. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 parsing [vpbx-stockbrockers-jhb.bitcovoice.com->call forward all] continue=false
80. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 Regex (FAIL) [call forward all] ${user_exists}(false) =~ /true/ break=on-false
81. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 parsing [vpbx-stockbrockers-jhb.bitcovoice.com->call forward not registered] continue=false
82. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 Regex (FAIL) [call forward not registered] ${user_exists}(false) =~ /true/ break=on-false
83. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 parsing [vpbx-stockbrockers-jhb.bitcovoice.com->talking clock date and time] continue=true
84. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 Regex (FAIL) [talking clock date and time] destination_number(*87201) =~ /^\*9172$/ break=on-false
85. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 parsing [vpbx-stockbrockers-jhb.bitcovoice.com->talking clock time] continue=true
86. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 Regex (FAIL) [talking clock time] destination_number(*87201) =~ /^\*9170$/ break=on-false
87. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 parsing [vpbx-stockbrockers-jhb.bitcovoice.com->talking clock date] continue=true
88. Dialplan: sofia/internal/4000@vpbx-stockbrockers-jhb.bitcovoice.com:5060 Regex (FAIL) [talking clock date] destination_number(*87201) =~ /^\*9171$/ break=on-false
89.