2022-06-29 11:18:29.829697 98.37% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [689@102.220.200.133] from ip 62.197.144.11
2022-06-29 11:18:56.229690 99.43% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [768@102.220.200.133] from ip 62.197.148.4
2022-06-29 11:18:56.909630 99.27% [WARNING] sofia_reg.c:3223 Can't find user [768@102.220.200.133] from 62.197.148.4
You must define a domain called '102.220.200.133' in your directory and add a user with the id="768" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:18:56.909630 99.27% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [768@102.220.200.133] from ip 62.197.148.4
freeswitch@pbx> 
freeswitch@pbx> 
2022-06-29 11:19:36.549694 99.30% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [741@102.220.200.133] from ip 45.129.32.39
2022-06-29 11:19:37.129695 99.33% [WARNING] sofia_reg.c:3223 Can't find user [741@102.220.200.133] from 45.129.32.39
You must define a domain called '102.220.200.133' in your directory and add a user with the id="741" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:19:37.129695 99.33% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [741@102.220.200.133] from ip 45.129.32.39
2022-06-29 11:19:52.289698 99.33% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [690@102.220.200.133] from ip 212.102.48.16
2022-06-29 11:19:52.509691 99.33% [WARNING] sofia_reg.c:3223 Can't find user [690@102.220.200.133] from 212.102.48.16
You must define a domain called '102.220.200.133' in your directory and add a user with the id="690" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:19:52.509691 99.33% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [690@102.220.200.133] from ip 212.102.48.16
2022-06-29 11:19:53.769698 99.33% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [767@102.220.200.133] from ip 89.37.173.54
2022-06-29 11:19:53.969694 99.33% [WARNING] sofia_reg.c:3223 Can't find user [767@102.220.200.133] from 89.37.173.54
You must define a domain called '102.220.200.133' in your directory and add a user with the id="767" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:19:53.969694 99.33% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [767@102.220.200.133] from ip 89.37.173.54
2022-06-29 11:19:58.729699 99.17% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [575@102.220.200.133] from ip 45.136.155.49
2022-06-29 11:19:59.189699 99.17% [WARNING] sofia_reg.c:3223 Can't find user [575@102.220.200.133] from 45.136.155.49
You must define a domain called '102.220.200.133' in your directory and add a user with the id="575" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:19:59.189699 99.17% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [575@102.220.200.133] from ip 45.136.155.49
2022-06-29 11:20:18.869689 98.57% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [761@102.220.200.133] from ip 194.169.170.4
2022-06-29 11:20:19.349664 98.57% [WARNING] sofia_reg.c:3223 Can't find user [761@102.220.200.133] from 194.169.170.4
You must define a domain called '102.220.200.133' in your directory and add a user with the id="761" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:20:19.349664 98.57% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [761@102.220.200.133] from ip 194.169.170.4
2022-06-29 11:20:29.169695 98.67% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 212.102.40.87
2022-06-29 11:20:29.609664 98.67% [WARNING] sofia_reg.c:3223 Can't find user [769@102.220.200.133] from 212.102.40.87
You must define a domain called '102.220.200.133' in your directory and add a user with the id="769" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:20:29.609664 98.67% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 212.102.40.87
2022-06-29 11:20:42.369699 99.37% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [768@102.220.200.133] from ip 138.199.60.166
2022-06-29 11:20:43.949694 99.33% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [766@102.220.200.133] from ip 45.136.155.56
2022-06-29 11:20:44.369645 99.33% [WARNING] sofia_reg.c:3223 Can't find user [766@102.220.200.133] from 45.136.155.56
You must define a domain called '102.220.200.133' in your directory and add a user with the id="766" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:20:44.369645 99.33% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [766@102.220.200.133] from ip 45.136.155.56
2022-06-29 11:21:14.269691 97.53% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [690@102.220.200.133] from ip 143.244.42.103
2022-06-29 11:21:14.529700 97.53% [WARNING] sofia_reg.c:3223 Can't find user [690@102.220.200.133] from 143.244.42.103
You must define a domain called '102.220.200.133' in your directory and add a user with the id="690" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:21:14.529700 97.53% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [690@102.220.200.133] from ip 143.244.42.103
2022-06-29 11:21:32.409693 98.50% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 45.136.155.91
2022-06-29 11:21:32.649695 99.00% [WARNING] sofia_reg.c:3223 Can't find user [769@102.220.200.133] from 45.136.155.91
You must define a domain called '102.220.200.133' in your directory and add a user with the id="769" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:21:32.649695 99.00% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 45.136.155.91
2022-06-29 11:21:38.769692 99.40% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [4023@102.220.200.133] from ip 85.14.245.202
2022-06-29 11:21:40.009696 99.40% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [768@102.220.200.133] from ip 85.204.124.94
2022-06-29 11:21:40.429702 99.40% [WARNING] sofia_reg.c:3223 Can't find user [768@102.220.200.133] from 85.204.124.94
You must define a domain called '102.220.200.133' in your directory and add a user with the id="768" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:21:40.429702 99.40% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [768@102.220.200.133] from ip 85.204.124.94
2022-06-29 11:21:49.209707 97.77% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [766@102.220.200.133] from ip 45.134.224.25
2022-06-29 11:21:49.769627 97.63% [WARNING] sofia_reg.c:3223 Can't find user [766@102.220.200.133] from 45.134.224.25
You must define a domain called '102.220.200.133' in your directory and add a user with the id="766" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:21:49.769627 97.63% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [766@102.220.200.133] from ip 45.134.224.25
2022-06-29 11:21:55.649691 95.73% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [653@102.220.200.133] from ip 92.62.120.6
2022-06-29 11:21:55.849673 95.73% [WARNING] sofia_reg.c:3223 Can't find user [653@102.220.200.133] from 92.62.120.6
You must define a domain called '102.220.200.133' in your directory and add a user with the id="653" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:21:55.849673 95.73% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [653@102.220.200.133] from ip 92.62.120.6
2022-06-29 11:21:56.289698 95.73% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 62.197.148.11
2022-06-29 11:21:56.589694 95.73% [WARNING] sofia_reg.c:3223 Can't find user [769@102.220.200.133] from 62.197.148.11
You must define a domain called '102.220.200.133' in your directory and add a user with the id="769" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:21:56.589694 95.73% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 62.197.148.11
2022-06-29 11:22:19.369674 95.83% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [676@102.220.200.133] from ip 62.197.144.9
2022-06-29 11:22:29.249695 97.90% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [687@102.220.200.133] from ip 193.218.35.13
2022-06-29 11:22:29.849694 98.07% [WARNING] sofia_reg.c:3223 Can't find user [687@102.220.200.133] from 193.218.35.13
You must define a domain called '102.220.200.133' in your directory and add a user with the id="687" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:22:29.849694 98.07% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [687@102.220.200.133] from ip 193.218.35.13
2022-06-29 11:23:19.469642 98.30% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [766@102.220.200.133] from ip 62.197.152.9
2022-06-29 11:23:20.669689 98.27% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [672@102.220.200.133] from ip 93.190.138.235
2022-06-29 11:23:20.909692 98.27% [WARNING] sofia_reg.c:3223 Can't find user [672@102.220.200.133] from 93.190.138.235
You must define a domain called '102.220.200.133' in your directory and add a user with the id="672" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:23:20.909692 98.27% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [672@102.220.200.133] from ip 93.190.138.235
2022-06-29 11:23:26.669693 98.37% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [689@102.220.200.133] from ip 156.146.45.104
2022-06-29 11:23:27.309662 98.37% [WARNING] sofia_reg.c:3223 Can't find user [689@102.220.200.133] from 156.146.45.104
You must define a domain called '102.220.200.133' in your directory and add a user with the id="689" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:23:27.309662 98.37% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [689@102.220.200.133] from ip 156.146.45.104
2022-06-29 11:23:29.469692 98.47% [NOTICE] switch_channel.c:1123 New Channel sofia/default/0902@102.220.200.133 [c77f3a33-e1b5-4002-a208-36f81f0e0384]
2022-06-29 11:23:29.469692 98.47% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_NEW (Cur 1 Tot 703)
2022-06-29 11:23:29.469692 98.47% [INFO] sofia.c:10462 sofia/default/0902@102.220.200.133 receiving invite from 102.220.201.145:5060 version: 1.10.7 -release-19-883d2cb662 64bit call-id: 5ecd981b-c1505d22@102.220.201.145
2022-06-29 11:23:29.469692 98.47% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 102.220.201.145:0.
2022-06-29 11:23:29.469692 98.47% [WARNING] sofia_reg.c:1861 SIP auth challenge (INVITE) on sofia profile 'default' for [0000@102.220.200.133] from ip 102.220.201.145
2022-06-29 11:23:29.469692 98.47% [DEBUG] switch_core_state_machine.c:600 (sofia/default/0902@102.220.200.133) State NEW
2022-06-29 11:23:29.469692 98.47% [DEBUG] sofia.c:2419 detaching session c77f3a33-e1b5-4002-a208-36f81f0e0384
2022-06-29 11:23:29.489628 98.47% [DEBUG] sofia.c:2532 Re-attaching to session c77f3a33-e1b5-4002-a208-36f81f0e0384
2022-06-29 11:23:29.489628 98.47% [INFO] sofia.c:10462 sofia/default/0902@102.220.200.133 receiving invite from 102.220.201.145:5060 version: 1.10.7 -release-19-883d2cb662 64bit call-id: 5ecd981b-c1505d22@102.220.201.145
2022-06-29 11:23:29.489628 98.47% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 102.220.201.145:0.
2022-06-29 11:23:29.509637 98.47% [DEBUG] sofia.c:7499 Channel sofia/default/0902@102.220.200.133 entering state [received][100]
2022-06-29 11:23:29.509637 98.47% [DEBUG] sofia.c:7509 Remote SDP:
v=0
o=- 14867458 14867458 IN IP4 102.220.201.145
s=-
c=IN IP4 102.220.201.145
t=0 0
m=audio 16536 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:30

2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:30:64000:1]/[PCMA:8:8000:20:64000:1]
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:30:64000:1]/[PCMU:0:8000:20:64000:1]
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5686 Audio Codec Compare [PCMU:0:8000:20:64000:1] is saved as a near-match
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-32:2:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-32:2:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:30:64000:1]/[PCMA:8:8000:20:64000:1]
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5686 Audio Codec Compare [PCMA:8:8000:20:64000:1] is saved as a near-match
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:30:64000:1]/[PCMU:0:8000:20:64000:1]
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G722:9:8000:30:64000:1]/[PCMA:8:8000:20:64000:1]
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G722:9:8000:30:64000:1]/[PCMU:0:8000:20:64000:1]
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729a:18:8000:30:8000:1]/[PCMA:8:8000:20:64000:1]
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729a:18:8000:30:8000:1]/[PCMU:0:8000:20:64000:1]
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-40:96:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-40:96:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-24:97:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-24:97:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-16:98:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-16:98:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5566 Set telephone-event payload to 101@8000
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5757 Substituting codec PCMU@30i@8000h@1c
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:3870 Set Codec sofia/default/0902@102.220.200.133 PCMU/8000 30 ms 240 samples 64000 bits 1 channels
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_codec.c:111 sofia/default/0902@102.220.200.133 Original read codec set to PCMU:0
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5915 Set telephone-event payload to 101@8000
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5973 sofia/default/0902@102.220.200.133 Set 2833 dtmf send payload to 101 recv payload to 101
2022-06-29 11:23:29.509637 98.47% [DEBUG] sofia.c:7933 (sofia/default/0902@102.220.200.133) State Change CS_NEW -> CS_INIT
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_INIT (Cur 1 Tot 703)
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_state_machine.c:624 (sofia/default/0902@102.220.200.133) State INIT
2022-06-29 11:23:29.509637 98.47% [DEBUG] mod_sofia.c:97 sofia/default/0902@102.220.200.133 SOFIA INIT
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_state_machine.c:40 sofia/default/0902@102.220.200.133 Standard INIT
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_state_machine.c:48 (sofia/default/0902@102.220.200.133) State Change CS_INIT -> CS_ROUTING
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_state_machine.c:624 (sofia/default/0902@102.220.200.133) State INIT going to sleep
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_ROUTING (Cur 1 Tot 703)
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_channel.c:2380 (sofia/default/0902@102.220.200.133) Callstate Change DOWN -> RINGING
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_state_machine.c:640 (sofia/default/0902@102.220.200.133) State ROUTING
2022-06-29 11:23:29.509637 98.47% [DEBUG] mod_sofia.c:158 sofia/default/0902@102.220.200.133 SOFIA ROUTING
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_state_machine.c:230 sofia/default/0902@102.220.200.133 Standard ROUTING
2022-06-29 11:23:29.509637 98.47% [INFO] mod_dialplan_xml.c:639 Processing 0902 <0902>->0000 in context default
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes')
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
2022-06-29 11:23:29.509637 98.47% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] Dialed number : 0000
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT access_number FROM accessnumber WHERE access_number = '0000' AND status=0 limit 1
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Generated XML:
<?xml version="1.0" encoding="UTF-8" standalone="no"?>
<document type="freeswitch/xml">
<section name="dialplan" description="ASTPP Dialplan">
<context name="default">
<extension name="0000">
<condition field="destination_number" expression="0000">
<action application="log" data="INFO ASTPP - Calling Card Call"/>
<action application="answer"/>
<action application="sleep" data="2000"/>
<action application="lua" data="astpp-callingcards.lua"/>
</condition>
</extension>
</context>
</section>
</document>
Dialplan: sofia/default/0902@102.220.200.133 parsing [default->0000] continue=false
Dialplan: sofia/default/0902@102.220.200.133 Regex (PASS) [0000] destination_number(0000) =~ /0000/ break=on-false
Dialplan: sofia/default/0902@102.220.200.133 Action log(INFO ASTPP - Calling Card Call) 
Dialplan: sofia/default/0902@102.220.200.133 Action answer() 
Dialplan: sofia/default/0902@102.220.200.133 Action sleep(2000) 
Dialplan: sofia/default/0902@102.220.200.133 Action lua(astpp-callingcards.lua) 
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_state_machine.c:281 (sofia/default/0902@102.220.200.133) State Change CS_ROUTING -> CS_EXECUTE
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_state_machine.c:640 (sofia/default/0902@102.220.200.133) State ROUTING going to sleep
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_EXECUTE (Cur 1 Tot 703)
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_state_machine.c:647 (sofia/default/0902@102.220.200.133) State EXECUTE
2022-06-29 11:23:29.509637 98.47% [DEBUG] mod_sofia.c:213 sofia/default/0902@102.220.200.133 SOFIA EXECUTE
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_state_machine.c:323 sofia/default/0902@102.220.200.133 Standard EXECUTE
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 log(INFO ASTPP - Calling Card Call)
2022-06-29 11:23:29.509637 98.47% [INFO] mod_dptools.c:1879 ASTPP - Calling Card Call
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 answer()
2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:8777 AUDIO RTP [sofia/default/0902@102.220.200.133] 102.220.200.133 port 17842 -> 102.220.201.145 port 16536 codec: 0 ms: 30
2022-06-29 11:23:29.529616 98.47% [DEBUG] switch_rtp.c:4619 Starting timer [soft] 240 bytes per 30ms
2022-06-29 11:23:29.549641 98.47% [DEBUG] switch_core_media.c:9089 sofia/default/0902@102.220.200.133 Set 2833 dtmf send payload to 101
2022-06-29 11:23:29.549641 98.47% [DEBUG] switch_core_media.c:9096 sofia/default/0902@102.220.200.133 Set 2833 dtmf receive payload to 101
2022-06-29 11:23:29.549641 98.47% [DEBUG] switch_core_media.c:9119 sofia/default/0902@102.220.200.133 Set rtp dtmf delay to 40
2022-06-29 11:23:29.549641 98.47% [DEBUG] mod_sofia.c:913 Local SDP sofia/default/0902@102.220.200.133:
v=0
o=FreeSWITCH 1656473167 1656473168 IN IP4 102.220.200.133
s=FreeSWITCH
c=IN IP4 102.220.200.133
t=0 0
m=audio 17842 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:30
a=sendrecv

2022-06-29 11:23:29.549641 98.47% [NOTICE] mod_dptools.c:1419 Channel [sofia/default/0902@102.220.200.133] has been answered
2022-06-29 11:23:29.549641 98.47% [DEBUG] switch_channel.c:3950 (sofia/default/0902@102.220.200.133) Callstate Change RINGING -> ACTIVE
2022-06-29 11:23:29.549641 98.47% [DEBUG] sofia.c:7499 Channel sofia/default/0902@102.220.200.133 entering state [completed][200]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 sleep(2000)
2022-06-29 11:23:29.669641 98.43% [DEBUG] sofia.c:7499 Channel sofia/default/0902@102.220.200.133 entering state [ready][200]
2022-06-29 11:23:29.689688 98.43% [DEBUG] switch_rtp.c:7934 Correct audio ip/port confirmed.
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 lua(astpp-callingcards.lua)
2022-06-29 11:23:31.569700 98.37% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes')
2022-06-29 11:23:31.589620 98.37% [NOTICE] switch_cpp.cpp:1465 [ASTPP] SECTION 
2022-06-29 11:23:31.589620 98.37% [DEBUG] switch_core_file.c:444 File /var/www/html/astpp/upload/astpp-welcome.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:23:31.589620 98.37% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:23:33.349699 98.93% [DEBUG] switch_ivr_play_say.c:2001 done playing file /var/www/html/astpp/upload/astpp-welcome.wav
2022-06-29 11:23:33.369672 98.93% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-accountnum.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:23:33.369672 98.93% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:23:36.349693 99.10% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-accountnum.wav
2022-06-29 11:23:38.289678 99.17% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:1040
2022-06-29 11:23:38.289678 99.17% [INFO] switch_channel.c:527 RECV DTMF 7:1040
2022-06-29 11:23:38.709691 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:1200
2022-06-29 11:23:38.709691 99.13% [INFO] switch_channel.c:527 RECV DTMF 1:1200
2022-06-29 11:23:39.169694 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 8:1200
2022-06-29 11:23:39.169694 99.13% [INFO] switch_channel.c:527 RECV DTMF 8:1200
2022-06-29 11:23:39.669690 99.17% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF #:2000
2022-06-29 11:23:39.669690 99.17% [INFO] switch_channel.c:527 RECV DTMF #:2000
2022-06-29 11:23:39.689644 99.17% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Got DTMF digits: 718
2022-06-29 11:23:39.689644 99.17% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT *,(select currencyrate from currency where id=currency_id) as currencyrate FROM accounts WHERE number = "718" AND status=0 AND deleted=0 limit 1
2022-06-29 11:23:39.689644 99.17% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-badaccount.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:23:39.689644 99.17% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:23:41.289691 99.17% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-badaccount.wav
2022-06-29 11:23:41.309659 99.17% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-accountnum.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:23:41.309659 99.17% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:23:44.289628 99.10% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-accountnum.wav
2022-06-29 11:23:44.629699 99.10% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:1520
2022-06-29 11:23:44.629699 99.10% [INFO] switch_channel.c:527 RECV DTMF 1:1520
2022-06-29 11:23:45.049695 99.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 2:1200
2022-06-29 11:23:45.049695 99.07% [INFO] switch_channel.c:527 RECV DTMF 2:1200
2022-06-29 11:23:45.429698 99.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:1040
2022-06-29 11:23:45.429698 99.07% [INFO] switch_channel.c:527 RECV DTMF 7:1040
2022-06-29 11:23:45.709690 99.10% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:960
2022-06-29 11:23:45.709690 99.10% [INFO] switch_channel.c:527 RECV DTMF 7:960
2022-06-29 11:23:46.069655 99.10% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:1200
2022-06-29 11:23:46.069655 99.10% [INFO] switch_channel.c:527 RECV DTMF 1:1200
2022-06-29 11:23:46.509690 99.10% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 8:1360
2022-06-29 11:23:46.509690 99.10% [INFO] switch_channel.c:527 RECV DTMF 8:1360
2022-06-29 11:23:46.969669 99.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF #:1760
2022-06-29 11:23:46.969669 99.07% [INFO] switch_channel.c:527 RECV DTMF #:1760
2022-06-29 11:23:46.969669 99.07% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Got DTMF digits: 127718
2022-06-29 11:23:46.969669 99.07% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT *,(select currencyrate from currency where id=currency_id) as currencyrate FROM accounts WHERE number = "127718" AND status=0 AND deleted=0 limit 1
2022-06-29 11:23:46.989702 99.07% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-pleasepin.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:23:46.989702 99.07% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:23:49.689695 99.17% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-pleasepin.wav
2022-06-29 11:23:50.709692 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 6:1360
2022-06-29 11:23:50.709692 99.13% [INFO] switch_channel.c:527 RECV DTMF 6:1360
2022-06-29 11:23:50.989700 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 3:960
2022-06-29 11:23:50.989700 99.13% [INFO] switch_channel.c:527 RECV DTMF 3:960
2022-06-29 11:23:51.369694 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:1040
2022-06-29 11:23:51.369694 99.13% [INFO] switch_channel.c:527 RECV DTMF 1:1040
2022-06-29 11:23:51.709645 99.17% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 4:1040
2022-06-29 11:23:51.709645 99.17% [INFO] switch_channel.c:527 RECV DTMF 4:1040
2022-06-29 11:23:52.269690 99.17% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF #:1840
2022-06-29 11:23:52.269690 99.17% [INFO] switch_channel.c:527 RECV DTMF #:1840
2022-06-29 11:23:52.289641 99.17% [DEBUG] switch_cpp.cpp:1465 [ASTPP] We recieved a pin : 6314
2022-06-29 11:23:52.289641 99.17% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [validate_card_usage] Query :SELECT DATE_FORMAT('2032-06-21 10:11:08' , '%Y%m%d%H%i%s') AS expiry
2022-06-29 11:23:52.289641 99.17% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [validate_card_usage] Query :SELECT DATE_FORMAT('2022-06-29 08:23:52' , '%Y%m%d%H%i%s') AS expiry
2022-06-29 11:23:52.289641 99.17% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [Accountcode : 127718]
2022-06-29 11:23:52.289641 99.17% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-this-card-has-a-balance-of.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:23:52.289641 99.17% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:23:53.589691 99.13% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-this-card-has-a-balance-of.wav
2022-06-29 11:23:53.609640 99.13% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [Play Amount First Part] Query :5000
2022-06-29 11:23:53.609640 99.13% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [Play Amount Second Part] Query :00
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 say(en number pronounced 5000)
2022-06-29 11:23:53.629633 99.13% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:23:54.829692 99.10% [DEBUG] switch_ivr_play_say.c:2001 done playing file file_string://digits/5.wav!digits/thousand.wav
2022-06-29 11:23:54.829692 99.10% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-point.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:23:54.849637 99.10% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:23:55.389693 99.10% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-point.wav
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 say(en number pronounced 00)
2022-06-29 11:23:55.429635 99.10% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:23:56.169702 99.07% [DEBUG] switch_ivr_play_say.c:2001 done playing file file_string://digits/0.wav
2022-06-29 11:23:56.209664 99.07% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-phonenum.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:23:56.209664 99.07% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:23:59.889694 98.77% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-phonenum.wav
2022-06-29 11:24:00.169684 98.77% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 0:1680
2022-06-29 11:24:00.169684 98.77% [INFO] switch_channel.c:527 RECV DTMF 0:1680
2022-06-29 11:24:00.529697 98.77% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:960
2022-06-29 11:24:00.529697 98.77% [INFO] switch_channel.c:527 RECV DTMF 7:960
2022-06-29 11:24:00.949695 98.80% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 9:720
2022-06-29 11:24:00.949695 98.80% [INFO] switch_channel.c:527 RECV DTMF 9:720
2022-06-29 11:24:02.109691 98.67% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 9:1120
2022-06-29 11:24:02.109691 98.67% [INFO] switch_channel.c:527 RECV DTMF 9:1120
2022-06-29 11:24:02.529691 98.67% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 2:960
2022-06-29 11:24:02.529691 98.67% [INFO] switch_channel.c:527 RECV DTMF 2:960
2022-06-29 11:24:02.949662 98.50% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 0:1360
2022-06-29 11:24:02.949662 98.50% [INFO] switch_channel.c:527 RECV DTMF 0:1360
2022-06-29 11:24:03.249672 98.50% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 5:720
2022-06-29 11:24:03.249672 98.50% [INFO] switch_channel.c:527 RECV DTMF 5:720
2022-06-29 11:24:03.609691 98.50% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 0:1040
2022-06-29 11:24:03.609691 98.50% [INFO] switch_channel.c:527 RECV DTMF 0:1040
2022-06-29 11:24:03.969679 98.50% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 9:1200
2022-06-29 11:24:03.969679 98.50% [INFO] switch_channel.c:527 RECV DTMF 9:1200
2022-06-29 11:24:04.309693 98.50% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:1040
2022-06-29 11:24:04.309693 98.50% [INFO] switch_channel.c:527 RECV DTMF 7:1040
2022-06-29 11:24:04.729694 98.50% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF #:1200
2022-06-29 11:24:04.729694 98.50% [INFO] switch_channel.c:527 RECV DTMF #:1200
2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] [CHECK_destination] Dialed destination number :0799205097
2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Account Information ===================
2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] User id : 17
2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] Account code : 127718
2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] Balance : 5000
2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] Type : 0 [0:prepaid,1:postpaid]
2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] Ratecard id : 4
2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] ========================================================
2022-06-29 11:24:04.729694 98.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CHECK_BLOCKED_PREFIX] Query :SELECT * FROM block_patterns WHERE (blocked_patterns = '^0799205097.*' OR blocked_patterns = '^079920509.*' OR blocked_patterns = '^07992050.*' OR blocked_patterns = '^0799205.*' OR blocked_patterns = '^079920.*' OR blocked_patterns = '^07992.*' OR blocked_patterns = '^0799.*' OR blocked_patterns = '^079.*' OR blocked_patterns = '^07.*' OR blocked_patterns = '^0.*' OR blocked_patterns ='--') AND accountid = 17 limit 1 
2022-06-29 11:24:04.729694 98.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_PACKAGE_INFO] Query :SELECT *,P.id as package_id,P.product_id as product_id FROM packages_view as P inner join package_patterns as PKGPTR on P.product_id = PKGPTR.product_id WHERE (patterns = '^0799205097.*' OR patterns = '^079920509.*' OR patterns = '^07992050.*' OR patterns = '^0799205.*' OR patterns = '^079920.*' OR patterns = '^07992.*' OR patterns = '^0799.*' OR patterns = '^079.*' OR patterns = '^07.*' OR patterns = '^0.*' OR patterns ='--') AND accountid = 17 ORDER BY LENGTH(PKGPTR.patterns) DESC
2022-06-29 11:24:04.729694 98.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 4 AND status = 0
2022-06-29 11:24:04.729694 98.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_RATES] call_direction :
2022-06-29 11:24:04.729694 98.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_RATES] Query :SELECT * FROM routes WHERE (pattern = '^0799205097.*' OR pattern = '^079920509.*' OR pattern = '^07992050.*' OR pattern = '^0799205.*' OR pattern = '^079920.*' OR pattern = '^07992.*' OR pattern = '^0799.*' OR pattern = '^079.*' OR pattern = '^07.*' OR pattern = '^0.*' OR pattern ='--') AND status = 0 AND (pricelist_id = 4 OR accountid=17)  ORDER BY accountid DESC,LENGTH(pattern) DESC,cost DESC LIMIT 1
2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] call_direction:::::: 
2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Rates Information ===================
2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] ID : 11
2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] Connectcost : 0.00000
2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] Includedseconds : 0
2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] Cost : 220.00000
2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] comment : Uganda
2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] Country Id : 197
2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] Accid : 17
2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] Trunk ID: 3
2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] Routing type: 
2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] ================================================================
2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] [FIND_MAXLENGTH] Your5000 balance Accountid 17 !!!
2022-06-29 11:24:04.729694 98.50% [NOTICE] switch_cpp.cpp:1465 [ASTPP] 22 Minutes
2022-06-29 11:24:04.729694 98.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [SAY_TIMELIMIT] MINUTES 22
2022-06-29 11:24:04.729694 98.50% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-this-call-will-last.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:24:04.729694 98.50% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:24:05.929692 98.50% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-this-call-will-last.wav
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 say(en number pronounced 22)
2022-06-29 11:24:05.969646 98.50% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:24:07.029692 98.43% [DEBUG] switch_ivr_play_say.c:2001 done playing file file_string://digits/20.wav!digits/2.wav
2022-06-29 11:24:07.069658 98.43% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-minutes.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:24:07.069658 98.43% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:24:07.669698 98.43% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-minutes.wav
2022-06-29 11:24:07.669698 98.43% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_CARRIER_RATES] Query :SELECT TK.id as trunk_id,TK.name as trunk_name,TK.codec,GW.name as path,GW.dialplan_variable,TK.provider_id,TR.init_inc,TK.status,TK.maxchannels,TK.cps,TK.leg_timeout,TR.pattern,TR.id as outbound_route_id,TR.connectcost,TR.comment,TR.includedseconds,TR.cost,TR.inc,TR.prepend,TR.strip,(select name from gateways where status=0 AND id = TK.failover_gateway_id) as path1,(select name from gateways where status=0 AND id = TK.failover_gateway_id1) as path2 FROM outbound_routes as TR,trunks as TK,gateways as GW WHERE GW.status=0 AND GW.id= TK.gateway_id AND TK.status=0 AND TK.id= TR.trunk_id AND (pattern = '^0799205097.*' OR pattern = '^079920509.*' OR pattern = '^07992050.*' OR pattern = '^0799205.*' OR pattern = '^079920.*' OR pattern = '^07992.*' OR pattern = '^0799.*' OR pattern = '^079.*' OR pattern = '^07.*' OR pattern = '^0.*' OR pattern ='--') AND TR.status = 0  AND TR.trunk_id IN (3)  ORDER by LENGTH (pattern) DESC,TR.cost ASC,TR.precedence ASC, TK.precedence
2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Termination Rates Information ===================
2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] ID : 7
2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] Code : ^0.*
2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] Destination : Uganda
2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] Connectcost : 0.00000
2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] Free Seconds : 0
2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] Prefix : ^0.*
2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] Strip : 
2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] Termination rate id : 3
2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] Gateway name : MTN
2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] Failover gateway : 
2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] Vendor id : 18
2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] Max channels : 0
2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] trunk_name : MTN
2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] =================================================================
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(call_processed=internal)
2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [call_processed]=[internal]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(callstart=2022-06-29 08:24:07)
2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [callstart]=[2022-06-29 08:24:07]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(originated_destination_number=0799205097)
2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [originated_destination_number]=[0799205097]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(effective_destination_number=0799205097)
2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [effective_destination_number]=[0799205097]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(continue_on_fail=true)
2022-06-29 11:24:07.709680 98.43% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [continue_on_fail]=[true]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(hangup_after_bridge=true)
2022-06-29 11:24:07.709680 98.43% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [hangup_after_bridge]=[true]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(account_id=17)
2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [account_id]=[17]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(account_type=0)
2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [account_type]=[0]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(resellerid=0)
2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [resellerid]=[0]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(parent_id=0)
2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [parent_id]=[0]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(accountcode=127718)
2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [accountcode]=[127718]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(call_direction=outbound)
2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [call_direction]=[outbound]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(calltype=CALLINGCARD)
2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [calltype]=[CALLINGCARD]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(origination_rates=ID:11|CODE:^0.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:|COST:220.00000|INC:2|INITIALBLOCK:1|RATEGROUP:4|MARKUP:0|CI:197|ACCID:17)
2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [origination_rates]=[ID:11|CODE:^0.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:|COST:220.00000|INC:2|INITIALBLOCK:1|RATEGROUP:4|MARKUP:0|CI:197|ACCID:17]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(execute_on_answer=sched_hangup +1320)
2022-06-29 11:24:07.709680 98.43% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [execute_on_answer]=[sched_hangup +1320]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(process_cdr=true)
2022-06-29 11:24:07.709680 98.43% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [process_cdr]=[true]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 sched_hangup(+1320)
2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_scheduler.c:263 Added task 4 switch_ivr_schedule_hangup (c77f3a33-e1b5-4002-a208-36f81f0e0384) to run at 1656492367
2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_OVERRIDE_CALLERID] Query :SELECT callerid_name as cid_name,callerid_number as cid_number,accountid FROM accounts_callerid WHERE accountid = 17 AND status=0 LIMIT 1
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(original_caller_id_name=0902)
2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [original_caller_id_name]=[0902]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(original_caller_id_number=0902)
2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [original_caller_id_number]=[0902]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(presence_data=x|||Dorcas(127718)|||^0.* // Uganda // 220.00000|||MTN // ^0.* // Uganda // 220.00000|||CC)
2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [presence_data]=[x|||Dorcas(127718)|||^0.* // Uganda // 220.00000|||MTN // ^0.* // Uganda // 220.00000|||CC]
2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,out_caller_id_terminate,number_terminate FROM localization WHERE id=(SELECT localization_id from accounts where id = 18) AND status=0 limit 1 
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(termination_rates=ID:7|CODE:^0.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:220.00000|INC:0|TRUNK:3|PROVIDER:18)
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [termination_rates]=[ID:7|CODE:^0.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:220.00000|INC:0|TRUNK:3|PROVIDER:18]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(trunk_id=3)
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [trunk_id]=[3]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(provider_id=18)
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [provider_id]=[18]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(hangup_after_bridge=false)
2022-06-29 11:24:07.729624 98.43% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [hangup_after_bridge]=[false]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(absolute_codec_string=PCMA,G729,PCMA)
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [absolute_codec_string]=[PCMA,G729,PCMA]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 bridge([leg_timeout=0]sofia/gateway/MTN/0799205097)
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1954 (sofia/default/0902@102.220.200.133) Callstate Change ACTIVE -> RING_WAIT
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [call_processed]=[internal] to event
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [callstart]=[2022-06-29 08:24:07] to event
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [originated_destination_number]=[0799205097] to event
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [effective_destination_number]=[0799205097] to event
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [account_id]=[17] to event
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [account_type]=[0] to event
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [resellerid]=[0] to event
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [parent_id]=[0] to event
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [accountcode]=[127718] to event
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [call_direction]=[outbound] to event
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [calltype]=[CALLINGCARD] to event
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [origination_rates]=[ID:11|CODE:^0.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:|COST:220.00000|INC:2|INITIALBLOCK:1|RATEGROUP:4|MARKUP:0|CI:197|ACCID:17] to event
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [original_caller_id_name]=[0902] to event
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [original_caller_id_number]=[0902] to event
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [presence_data]=[x|||Dorcas(127718)|||^0.* // Uganda // 220.00000|||MTN // ^0.* // Uganda // 220.00000|||CC] to event
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [termination_rates]=[ID:7|CODE:^0.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:220.00000|INC:0|TRUNK:3|PROVIDER:18] to event
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [trunk_id]=[3] to event
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [provider_id]=[18] to event
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [absolute_codec_string]=[PCMA,G729,PCMA] to event
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_ivr_originate.c:2843 Parsing session specific variables
2022-06-29 11:24:07.729624 98.43% [NOTICE] switch_channel.c:1123 New Channel sofia/default/0799205097 [0d73108c-c92d-4782-8abf-9a3de7c43c2c]
2022-06-29 11:24:07.729624 98.43% [DEBUG] mod_sofia.c:5121 (sofia/default/0799205097) State Change CS_NEW -> CS_INIT
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0799205097) Running State Change CS_INIT (Cur 2 Tot 704)
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:624 (sofia/default/0799205097) State INIT
2022-06-29 11:24:07.729624 98.43% [DEBUG] mod_sofia.c:97 sofia/default/0799205097 SOFIA INIT
2022-06-29 11:24:07.729624 98.43% [INFO] sofia_glue.c:1651 sofia/default/0799205097 sending invite call-id: (null)
2022-06-29 11:24:07.729624 98.43% [DEBUG] sofia_glue.c:1654 sofia/default/0799205097 sending invite version: 1.10.7 -release-19-883d2cb662 64bit
Local SDP:
v=0
o=FreeSWITCH 1656469267 1656469268 IN IP4 102.220.200.133
s=FreeSWITCH
c=IN IP4 102.220.200.133
t=0 0
m=audio 21780 RTP/AVP 8 18 101
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv

2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:40 sofia/default/0799205097 Standard INIT
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:48 (sofia/default/0799205097) State Change CS_INIT -> CS_ROUTING
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:624 (sofia/default/0799205097) State INIT going to sleep
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0799205097) Running State Change CS_ROUTING (Cur 2 Tot 704)
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:640 (sofia/default/0799205097) State ROUTING
2022-06-29 11:24:07.729624 98.43% [DEBUG] mod_sofia.c:158 sofia/default/0799205097 SOFIA ROUTING
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_ivr_originate.c:67 (sofia/default/0799205097) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:640 (sofia/default/0799205097) State ROUTING going to sleep
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0799205097) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 704)
2022-06-29 11:24:07.729624 98.43% [DEBUG] sofia.c:7499 Channel sofia/default/0799205097 entering state [calling][0]
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:659 (sofia/default/0799205097) State CONSUME_MEDIA
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:659 (sofia/default/0799205097) State CONSUME_MEDIA going to sleep
2022-06-29 11:24:07.729624 98.43% [DEBUG] sofia.c:7499 Channel sofia/default/0799205097 entering state [terminated][503]
2022-06-29 11:24:07.729624 98.43% [NOTICE] sofia.c:8738 Hangup sofia/default/0799205097 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE]
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0799205097) Running State Change CS_HANGUP (Cur 2 Tot 704)
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:844 (sofia/default/0799205097) Callstate Change DOWN -> HANGUP
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:846 (sofia/default/0799205097) State HANGUP
2022-06-29 11:24:07.729624 98.43% [DEBUG] mod_sofia.c:468 Channel sofia/default/0799205097 hanging up, cause: NORMAL_TEMPORARY_FAILURE
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE]
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:59 sofia/default/0799205097 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:846 (sofia/default/0799205097) State HANGUP going to sleep
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:616 (sofia/default/0799205097) State Change CS_HANGUP -> CS_REPORTING
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0799205097) Running State Change CS_REPORTING (Cur 2 Tot 704)
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:932 (sofia/default/0799205097) State REPORTING
2022-06-29 11:24:07.729624 98.43% [INFO] mod_json_cdr.c:271 Process [0d73108c-c92d-4782-8abf-9a3de7c43c2c.cdr.json]
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:2178 (sofia/default/0902@102.220.200.133) Callstate Change RING_WAIT -> ACTIVE
2022-06-29 11:24:07.729624 98.43% [INFO] mod_dptools.c:3653 Originate Failed.  Cause: NORMAL_TEMPORARY_FAILURE
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-callingcard-menu.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:24:07.789618 98.43% [DEBUG] switch_core_state_machine.c:168 sofia/default/0799205097 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
2022-06-29 11:24:07.789618 98.43% [DEBUG] switch_core_state_machine.c:932 (sofia/default/0799205097) State REPORTING going to sleep
2022-06-29 11:24:07.789618 98.43% [DEBUG] switch_core_state_machine.c:607 (sofia/default/0799205097) State Change CS_REPORTING -> CS_DESTROY
2022-06-29 11:24:07.789618 98.43% [DEBUG] switch_core_session.c:1753 Session 704 (sofia/default/0799205097) Locked, Waiting on external entities
2022-06-29 11:24:07.789618 98.43% [NOTICE] switch_core_session.c:1771 Session 704 (sofia/default/0799205097) Ended
2022-06-29 11:24:07.789618 98.43% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/0799205097 [CS_DESTROY]
2022-06-29 11:24:07.789618 98.43% [DEBUG] switch_core_state_machine.c:735 (sofia/default/0799205097) Running State Change CS_DESTROY (Cur 1 Tot 704)
2022-06-29 11:24:07.789618 98.43% [DEBUG] switch_core_state_machine.c:745 (sofia/default/0799205097) State DESTROY
2022-06-29 11:24:07.789618 98.43% [DEBUG] mod_sofia.c:379 sofia/default/0799205097 SOFIA DESTROY
2022-06-29 11:24:07.789618 98.43% [DEBUG] switch_core_state_machine.c:175 sofia/default/0799205097 Standard DESTROY
2022-06-29 11:24:07.789618 98.43% [DEBUG] switch_core_state_machine.c:745 (sofia/default/0799205097) State DESTROY going to sleep
2022-06-29 11:24:13.849696 98.10% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-callingcard-menu.wav
2022-06-29 11:24:19.389630 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:1760
2022-06-29 11:24:19.389630 98.07% [INFO] switch_channel.c:527 RECV DTMF 1:1760
2022-06-29 11:24:19.409639 98.07% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Got DTMF digits: 1retries:0
2022-06-29 11:24:19.409639 98.07% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT *,(select currencyrate from currency where id=currency_id) as currencyrate FROM accounts WHERE number = "17" AND status=0 AND deleted=0 limit 1
2022-06-29 11:24:19.409639 98.07% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-phonenum.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:24:19.409639 98.07% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:24:22.329670 98.07% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [686@102.220.200.133] from ip 2.58.241.4
2022-06-29 11:24:22.389692 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 0:1360
2022-06-29 11:24:22.389692 98.07% [INFO] switch_channel.c:527 RECV DTMF 0:1360
2022-06-29 11:24:22.409633 98.07% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-phonenum.wav
2022-06-29 11:24:22.689694 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:640
2022-06-29 11:24:22.689694 98.07% [INFO] switch_channel.c:527 RECV DTMF 7:640
2022-06-29 11:24:22.749689 98.07% [WARNING] sofia_reg.c:3223 Can't find user [686@102.220.200.133] from 2.58.241.4
You must define a domain called '102.220.200.133' in your directory and add a user with the id="686" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:24:22.749689 98.07% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [686@102.220.200.133] from ip 2.58.241.4
2022-06-29 11:24:22.989670 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:800
2022-06-29 11:24:22.989670 98.07% [INFO] switch_channel.c:527 RECV DTMF 7:800
2022-06-29 11:24:23.409693 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 9:1200
2022-06-29 11:24:23.409693 98.07% [INFO] switch_channel.c:527 RECV DTMF 9:1200
2022-06-29 11:24:23.829694 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 2:1280
2022-06-29 11:24:23.829694 98.07% [INFO] switch_channel.c:527 RECV DTMF 2:1280
2022-06-29 11:24:24.549697 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 0:1840
2022-06-29 11:24:24.549697 98.07% [INFO] switch_channel.c:527 RECV DTMF 0:1840
2022-06-29 11:24:25.009663 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 5:1040
2022-06-29 11:24:25.009663 98.07% [INFO] switch_channel.c:527 RECV DTMF 5:1040
2022-06-29 11:24:25.389694 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 0:1280
2022-06-29 11:24:25.389694 98.07% [INFO] switch_channel.c:527 RECV DTMF 0:1280
2022-06-29 11:24:25.749697 98.10% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 9:1040
2022-06-29 11:24:25.749697 98.10% [INFO] switch_channel.c:527 RECV DTMF 9:1040
2022-06-29 11:24:26.089694 98.10% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:800
2022-06-29 11:24:26.089694 98.10% [INFO] switch_channel.c:527 RECV DTMF 7:800
2022-06-29 11:24:26.529694 98.10% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF #:1360
2022-06-29 11:24:26.529694 98.10% [INFO] switch_channel.c:527 RECV DTMF #:1360
2022-06-29 11:24:26.549644 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] [CHECK_destination] Dialed destination number :0779205097
2022-06-29 11:24:26.549644 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Account Information ===================
2022-06-29 11:24:26.549644 98.10% [ERR] mod_lua.cpp:202 ...switch/scripts/astpp/lib/astpp.callingcard.functions.lua:598: attempt to index local 'userinfo' (a nil value)
stack traceback:
	...switch/scripts/astpp/lib/astpp.callingcard.functions.lua:598: in function 'process_destination'
	...switch/scripts/astpp/lib/astpp.callingcard.functions.lua:259: in function 'playback_ivr'
	/usr/share/freeswitch/scripts/astpp-callingcards.lua:106: in main chunk
2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_cpp.cpp:1209 sofia/default/0902@102.220.200.133 destroy/unlink session from object
2022-06-29 11:24:26.549644 98.10% [NOTICE] switch_core_state_machine.c:382 sofia/default/0902@102.220.200.133 has executed the last dialplan instruction, hanging up.
2022-06-29 11:24:26.549644 98.10% [NOTICE] switch_core_state_machine.c:384 Hangup sofia/default/0902@102.220.200.133 [CS_EXECUTE] [NORMAL_CLEARING]
2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:647 (sofia/default/0902@102.220.200.133) State EXECUTE going to sleep
2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_HANGUP (Cur 1 Tot 704)
2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:844 (sofia/default/0902@102.220.200.133) Callstate Change ACTIVE -> HANGUP
2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:846 (sofia/default/0902@102.220.200.133) State HANGUP
2022-06-29 11:24:26.549644 98.10% [DEBUG] mod_sofia.c:462 sofia/default/0902@102.220.200.133 Overriding SIP cause 480 with 503 from the other leg
2022-06-29 11:24:26.549644 98.10% [DEBUG] mod_sofia.c:468 Channel sofia/default/0902@102.220.200.133 hanging up, cause: NORMAL_CLEARING
2022-06-29 11:24:26.549644 98.10% [DEBUG] mod_sofia.c:522 Sending BYE to sofia/default/0902@102.220.200.133
2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:59 sofia/default/0902@102.220.200.133 Standard HANGUP, cause: NORMAL_CLEARING
2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:846 (sofia/default/0902@102.220.200.133) State HANGUP going to sleep
2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:616 (sofia/default/0902@102.220.200.133) State Change CS_HANGUP -> CS_REPORTING
2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_REPORTING (Cur 1 Tot 704)
2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:932 (sofia/default/0902@102.220.200.133) State REPORTING
2022-06-29 11:24:26.549644 98.10% [INFO] mod_json_cdr.c:271 Process [c77f3a33-e1b5-4002-a208-36f81f0e0384.cdr.json]
2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:168 sofia/default/0902@102.220.200.133 Standard REPORTING, cause: NORMAL_CLEARING
2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:932 (sofia/default/0902@102.220.200.133) State REPORTING going to sleep
2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:607 (sofia/default/0902@102.220.200.133) State Change CS_REPORTING -> CS_DESTROY
2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_session.c:1753 Session 703 (sofia/default/0902@102.220.200.133) Locked, Waiting on external entities
2022-06-29 11:24:26.549644 98.10% [NOTICE] switch_core_session.c:1771 Session 703 (sofia/default/0902@102.220.200.133) Ended
2022-06-29 11:24:26.549644 98.10% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/0902@102.220.200.133 [CS_DESTROY]
2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:735 (sofia/default/0902@102.220.200.133) Running State Change CS_DESTROY (Cur 0 Tot 704)
2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:745 (sofia/default/0902@102.220.200.133) State DESTROY
2022-06-29 11:24:26.549644 98.10% [DEBUG] mod_sofia.c:379 sofia/default/0902@102.220.200.133 SOFIA DESTROY
2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:175 sofia/default/0902@102.220.200.133 Standard DESTROY
2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:745 (sofia/default/0902@102.220.200.133) State DESTROY going to sleep
2022-06-29 11:24:26.689694 98.23% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [691@102.220.200.133] from ip 213.109.151.9
2022-06-29 11:24:26.709694 98.23% [DEBUG] switch_scheduler.c:147 Deleting task 4 switch_ivr_schedule_hangup (c77f3a33-e1b5-4002-a208-36f81f0e0384)
2022-06-29 11:24:47.429690 99.17% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [669@102.220.200.133] from ip 103.219.21.17
2022-06-29 11:25:08.789690 97.90% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [768@102.220.200.133] from ip 91.240.243.18
2022-06-29 11:25:09.069694 97.90% [WARNING] sofia_reg.c:3223 Can't find user [768@102.220.200.133] from 91.240.243.18
You must define a domain called '102.220.200.133' in your directory and add a user with the id="768" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:25:09.069694 97.90% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [768@102.220.200.133] from ip 91.240.243.18
2022-06-29 11:25:17.329698 97.77% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 62.197.148.4
2022-06-29 11:25:17.509693 97.77% [WARNING] sofia_reg.c:3223 Can't find user [769@102.220.200.133] from 62.197.148.4
You must define a domain called '102.220.200.133' in your directory and add a user with the id="769" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:25:17.509693 97.77% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 62.197.148.4
2022-06-29 11:25:36.489691 98.97% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [690@102.220.200.133] from ip 62.197.144.11
2022-06-29 11:25:36.709659 99.17% [WARNING] sofia_reg.c:3223 Can't find user [690@102.220.200.133] from 62.197.144.11
You must define a domain called '102.220.200.133' in your directory and add a user with the id="690" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:25:36.709659 99.17% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [690@102.220.200.133] from ip 62.197.144.11
2022-06-29 11:26:01.789673 98.97% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [742@102.220.200.133] from ip 45.129.32.39
2022-06-29 11:26:02.349691 98.97% [WARNING] sofia_reg.c:3223 Can't find user [742@102.220.200.133] from 45.129.32.39
You must define a domain called '102.220.200.133' in your directory and add a user with the id="742" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:26:02.349691 98.97% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [742@102.220.200.133] from ip 45.129.32.39
2022-06-29 11:26:39.169698 99.13% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [669@102.220.200.133] from ip 146.70.102.190
2022-06-29 11:26:39.709693 99.17% [WARNING] sofia_reg.c:3223 Can't find user [669@102.220.200.133] from 146.70.102.190
You must define a domain called '102.220.200.133' in your directory and add a user with the id="669" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:26:39.709693 99.17% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [669@102.220.200.133] from ip 146.70.102.190
2022-06-29 11:26:40.249694 99.17% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [762@102.220.200.133] from ip 194.169.170.4
2022-06-29 11:26:40.749693 99.17% [WARNING] sofia_reg.c:3223 Can't find user [762@102.220.200.133] from 194.169.170.4
You must define a domain called '102.220.200.133' in your directory and add a user with the id="762" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:26:40.749693 99.17% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [762@102.220.200.133] from ip 194.169.170.4
2022-06-29 11:26:50.429651 99.10% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [770@102.220.200.133] from ip 212.102.40.87
2022-06-29 11:26:55.769694 98.97% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [691@102.220.200.133] from ip 212.102.48.16
2022-06-29 11:26:56.009694 98.97% [WARNING] sofia_reg.c:3223 Can't find user [691@102.220.200.133] from 212.102.48.16
You must define a domain called '102.220.200.133' in your directory and add a user with the id="691" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:26:56.009694 98.97% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [691@102.220.200.133] from ip 212.102.48.16
2022-06-29 11:27:03.829695 98.20% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 62.197.156.4
2022-06-29 11:27:04.449690 98.20% [WARNING] sofia_reg.c:3223 Can't find user [769@102.220.200.133] from 62.197.156.4
You must define a domain called '102.220.200.133' in your directory and add a user with the id="769" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:27:04.449690 98.20% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 62.197.156.4
2022-06-29 11:27:05.269694 98.17% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [576@102.220.200.133] from ip 45.136.155.49
2022-06-29 11:27:05.489656 98.17% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [767@102.220.200.133] from ip 45.136.155.56
2022-06-29 11:27:05.729694 98.20% [WARNING] sofia_reg.c:3223 Can't find user [576@102.220.200.133] from 45.136.155.49
You must define a domain called '102.220.200.133' in your directory and add a user with the id="576" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:27:05.729694 98.20% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [576@102.220.200.133] from ip 45.136.155.49
2022-06-29 11:27:05.909683 98.20% [WARNING] sofia_reg.c:3223 Can't find user [767@102.220.200.133] from 45.136.155.56
You must define a domain called '102.220.200.133' in your directory and add a user with the id="767" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:27:05.909683 98.20% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [767@102.220.200.133] from ip 45.136.155.56
2022-06-29 11:27:11.769703 98.07% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [6688@102.220.200.133] from ip 85.14.245.202
2022-06-29 11:27:16.669697 98.03% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [691@102.220.200.133] from ip 45.43.19.83
2022-06-29 11:27:17.009693 98.03% [WARNING] sofia_reg.c:3223 Can't find user [691@102.220.200.133] from 45.43.19.83
You must define a domain called '102.220.200.133' in your directory and add a user with the id="691" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:27:17.009693 98.03% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [691@102.220.200.133] from ip 45.43.19.83
2022-06-29 11:27:29.229693 98.33% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [684@102.220.200.133] from ip 89.187.163.193
2022-06-29 11:27:29.909701 98.33% [WARNING] sofia_reg.c:3223 Can't find user [684@102.220.200.133] from 89.187.163.193
You must define a domain called '102.220.200.133' in your directory and add a user with the id="684" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:27:29.909701 98.33% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [684@102.220.200.133] from ip 89.187.163.193
2022-06-29 11:27:53.689695 99.33% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [770@102.220.200.133] from ip 45.136.155.91
2022-06-29 11:27:53.929694 99.33% [WARNING] sofia_reg.c:3223 Can't find user [770@102.220.200.133] from 45.136.155.91
You must define a domain called '102.220.200.133' in your directory and add a user with the id="770" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:27:53.929694 99.33% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [770@102.220.200.133] from ip 45.136.155.91
2022-06-29 11:28:01.469694 99.07% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 85.204.124.94
2022-06-29 11:28:01.889630 98.97% [WARNING] sofia_reg.c:3223 Can't find user [769@102.220.200.133] from 85.204.124.94
You must define a domain called '102.220.200.133' in your directory and add a user with the id="769" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:28:01.889630 98.97% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 85.204.124.94
2022-06-29 11:28:10.609699 98.10% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [767@102.220.200.133] from ip 45.134.224.25
2022-06-29 11:28:11.189690 98.13% [WARNING] sofia_reg.c:3223 Can't find user [767@102.220.200.133] from 45.134.224.25
You must define a domain called '102.220.200.133' in your directory and add a user with the id="767" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:28:11.189690 98.13% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [767@102.220.200.133] from ip 45.134.224.25
2022-06-29 11:28:17.529700 98.10% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [770@102.220.200.133] from ip 62.197.148.11
2022-06-29 11:28:17.809694 98.10% [WARNING] sofia_reg.c:3223 Can't find user [770@102.220.200.133] from 62.197.148.11
You must define a domain called '102.220.200.133' in your directory and add a user with the id="770" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:28:17.809694 98.10% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [770@102.220.200.133] from ip 62.197.148.11
2022-06-29 11:28:18.609693 98.10% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [691@102.220.200.133] from ip 143.244.46.216
2022-06-29 11:28:18.829699 98.10% [WARNING] sofia_reg.c:3223 Can't find user [691@102.220.200.133] from 143.244.46.216
You must define a domain called '102.220.200.133' in your directory and add a user with the id="691" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:28:18.829699 98.10% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [691@102.220.200.133] from ip 143.244.46.216
2022-06-29 11:29:07.749678 98.67% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [654@102.220.200.133] from ip 92.62.120.6
2022-06-29 11:29:07.949697 98.67% [WARNING] sofia_reg.c:3223 Can't find user [654@102.220.200.133] from 92.62.120.6
You must define a domain called '102.220.200.133' in your directory and add a user with the id="654" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:29:07.949697 98.67% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [654@102.220.200.133] from ip 92.62.120.6
2022-06-29 11:29:14.069699 98.63% [NOTICE] switch_channel.c:1123 New Channel sofia/default/3100102220200133@102.220.200.133 [016c9e35-f35c-40b0-9735-e08cdbb5ff77]
2022-06-29 11:29:14.069699 98.63% [DEBUG] switch_core_state_machine.c:581 (sofia/default/3100102220200133@102.220.200.133) Running State Change CS_NEW (Cur 1 Tot 705)
2022-06-29 11:29:14.069699 98.63% [INFO] sofia.c:10462 sofia/default/3100102220200133@102.220.200.133 receiving invite from 89.163.241.34:62465 version: 1.10.7 -release-19-883d2cb662 64bit call-id: 817916956-1907052724-425026322
2022-06-29 11:29:14.069699 98.63% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 89.163.241.34:0.
2022-06-29 11:29:14.069699 98.63% [WARNING] sofia_reg.c:1861 SIP auth challenge (INVITE) on sofia profile 'default' for [3100972595725668@102.220.200.133] from ip 89.163.241.34
2022-06-29 11:29:14.069699 98.63% [DEBUG] switch_core_state_machine.c:600 (sofia/default/3100102220200133@102.220.200.133) State NEW
2022-06-29 11:29:14.069699 98.63% [DEBUG] sofia.c:2419 detaching session 016c9e35-f35c-40b0-9735-e08cdbb5ff77
2022-06-29 11:29:24.109690 98.63% [WARNING] switch_core_state_machine.c:684 016c9e35-f35c-40b0-9735-e08cdbb5ff77 sofia/default/3100102220200133@102.220.200.133 Abandoned
2022-06-29 11:29:24.109690 98.63% [NOTICE] switch_core_state_machine.c:687 Hangup sofia/default/3100102220200133@102.220.200.133 [CS_NEW] [WRONG_CALL_STATE]
2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:581 (sofia/default/3100102220200133@102.220.200.133) Running State Change CS_HANGUP (Cur 1 Tot 705)
2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:844 (sofia/default/3100102220200133@102.220.200.133) Callstate Change DOWN -> HANGUP
2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:846 (sofia/default/3100102220200133@102.220.200.133) State HANGUP
2022-06-29 11:29:24.109690 98.63% [DEBUG] mod_sofia.c:468 Channel sofia/default/3100102220200133@102.220.200.133 hanging up, cause: WRONG_CALL_STATE
2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:59 sofia/default/3100102220200133@102.220.200.133 Standard HANGUP, cause: WRONG_CALL_STATE
2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:846 (sofia/default/3100102220200133@102.220.200.133) State HANGUP going to sleep
2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:616 (sofia/default/3100102220200133@102.220.200.133) State Change CS_HANGUP -> CS_REPORTING
2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:581 (sofia/default/3100102220200133@102.220.200.133) Running State Change CS_REPORTING (Cur 1 Tot 705)
2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:932 (sofia/default/3100102220200133@102.220.200.133) State REPORTING
2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:168 sofia/default/3100102220200133@102.220.200.133 Standard REPORTING, cause: WRONG_CALL_STATE
2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:932 (sofia/default/3100102220200133@102.220.200.133) State REPORTING going to sleep
2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:607 (sofia/default/3100102220200133@102.220.200.133) State Change CS_REPORTING -> CS_DESTROY
2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_session.c:1753 Session 705 (sofia/default/3100102220200133@102.220.200.133) Locked, Waiting on external entities
2022-06-29 11:29:24.109690 98.63% [NOTICE] switch_core_session.c:1771 Session 705 (sofia/default/3100102220200133@102.220.200.133) Ended
2022-06-29 11:29:24.109690 98.63% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/3100102220200133@102.220.200.133 [CS_DESTROY]
2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:735 (sofia/default/3100102220200133@102.220.200.133) Running State Change CS_DESTROY (Cur 0 Tot 705)
2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:745 (sofia/default/3100102220200133@102.220.200.133) State DESTROY
2022-06-29 11:29:24.109690 98.63% [DEBUG] mod_sofia.c:379 sofia/default/3100102220200133@102.220.200.133 SOFIA DESTROY
2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:175 sofia/default/3100102220200133@102.220.200.133 Standard DESTROY
2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:745 (sofia/default/3100102220200133@102.220.200.133) State DESTROY going to sleep
2022-06-29 11:29:33.209693 99.17% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [677@102.220.200.133] from ip 62.197.144.9
2022-06-29 11:29:33.569693 99.17% [WARNING] sofia_reg.c:3223 Can't find user [677@102.220.200.133] from 62.197.144.9
You must define a domain called '102.220.200.133' in your directory and add a user with the id="677" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:29:33.569693 99.17% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [677@102.220.200.133] from ip 62.197.144.9
2022-06-29 11:29:38.409698 99.13% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [688@102.220.200.133] from ip 193.218.35.13
2022-06-29 11:29:38.989644 99.13% [WARNING] sofia_reg.c:3223 Can't find user [688@102.220.200.133] from 193.218.35.13
You must define a domain called '102.220.200.133' in your directory and add a user with the id="688" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:29:38.989644 99.13% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [688@102.220.200.133] from ip 193.218.35.13
2022-06-29 11:29:41.949662 99.17% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [767@102.220.200.133] from ip 62.197.152.9
2022-06-29 11:29:42.349694 99.17% [WARNING] sofia_reg.c:3223 Can't find user [767@102.220.200.133] from 62.197.152.9
You must define a domain called '102.220.200.133' in your directory and add a user with the id="767" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:29:42.349694 99.17% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [767@102.220.200.133] from ip 62.197.152.9
2022-06-29 11:29:56.669692 98.97% [NOTICE] switch_channel.c:1123 New Channel sofia/default/0902@102.220.200.133 [c71261ca-c074-4061-a372-aa03d5185441]
2022-06-29 11:29:56.669692 98.97% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_NEW (Cur 1 Tot 706)
2022-06-29 11:29:56.669692 98.97% [INFO] sofia.c:10462 sofia/default/0902@102.220.200.133 receiving invite from 102.220.201.145:5060 version: 1.10.7 -release-19-883d2cb662 64bit call-id: bf2d6da2-79684487@102.220.201.145
2022-06-29 11:29:56.669692 98.97% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 102.220.201.145:0.
2022-06-29 11:29:56.669692 98.97% [WARNING] sofia_reg.c:1861 SIP auth challenge (INVITE) on sofia profile 'default' for [0000@102.220.200.133] from ip 102.220.201.145
2022-06-29 11:29:56.669692 98.97% [DEBUG] switch_core_state_machine.c:600 (sofia/default/0902@102.220.200.133) State NEW
2022-06-29 11:29:56.669692 98.97% [DEBUG] sofia.c:2419 detaching session c71261ca-c074-4061-a372-aa03d5185441
2022-06-29 11:29:56.689693 98.97% [DEBUG] sofia.c:2532 Re-attaching to session c71261ca-c074-4061-a372-aa03d5185441
2022-06-29 11:29:56.689693 98.97% [INFO] sofia.c:10462 sofia/default/0902@102.220.200.133 receiving invite from 102.220.201.145:5060 version: 1.10.7 -release-19-883d2cb662 64bit call-id: bf2d6da2-79684487@102.220.201.145
2022-06-29 11:29:56.689693 98.97% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 102.220.201.145:0.
2022-06-29 11:29:56.709636 98.97% [DEBUG] sofia.c:7499 Channel sofia/default/0902@102.220.200.133 entering state [received][100]
2022-06-29 11:29:56.709636 98.97% [DEBUG] sofia.c:7509 Remote SDP:
v=0
o=- 14906178 14906178 IN IP4 102.220.201.145
s=-
c=IN IP4 102.220.201.145
t=0 0
m=audio 16538 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:30

2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:30:64000:1]/[PCMA:8:8000:20:64000:1]
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:30:64000:1]/[PCMU:0:8000:20:64000:1]
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5686 Audio Codec Compare [PCMU:0:8000:20:64000:1] is saved as a near-match
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-32:2:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-32:2:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:30:64000:1]/[PCMA:8:8000:20:64000:1]
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5686 Audio Codec Compare [PCMA:8:8000:20:64000:1] is saved as a near-match
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:30:64000:1]/[PCMU:0:8000:20:64000:1]
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G722:9:8000:30:64000:1]/[PCMA:8:8000:20:64000:1]
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G722:9:8000:30:64000:1]/[PCMU:0:8000:20:64000:1]
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729a:18:8000:30:8000:1]/[PCMA:8:8000:20:64000:1]
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729a:18:8000:30:8000:1]/[PCMU:0:8000:20:64000:1]
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-40:96:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-40:96:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-24:97:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-24:97:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-16:98:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-16:98:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5566 Set telephone-event payload to 101@8000
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5757 Substituting codec PCMU@30i@8000h@1c
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:3870 Set Codec sofia/default/0902@102.220.200.133 PCMU/8000 30 ms 240 samples 64000 bits 1 channels
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_codec.c:111 sofia/default/0902@102.220.200.133 Original read codec set to PCMU:0
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5915 Set telephone-event payload to 101@8000
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5973 sofia/default/0902@102.220.200.133 Set 2833 dtmf send payload to 101 recv payload to 101
2022-06-29 11:29:56.709636 98.97% [DEBUG] sofia.c:7933 (sofia/default/0902@102.220.200.133) State Change CS_NEW -> CS_INIT
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_INIT (Cur 1 Tot 706)
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_state_machine.c:624 (sofia/default/0902@102.220.200.133) State INIT
2022-06-29 11:29:56.709636 98.97% [DEBUG] mod_sofia.c:97 sofia/default/0902@102.220.200.133 SOFIA INIT
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_state_machine.c:40 sofia/default/0902@102.220.200.133 Standard INIT
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_state_machine.c:48 (sofia/default/0902@102.220.200.133) State Change CS_INIT -> CS_ROUTING
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_state_machine.c:624 (sofia/default/0902@102.220.200.133) State INIT going to sleep
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_ROUTING (Cur 1 Tot 706)
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_channel.c:2380 (sofia/default/0902@102.220.200.133) Callstate Change DOWN -> RINGING
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_state_machine.c:640 (sofia/default/0902@102.220.200.133) State ROUTING
2022-06-29 11:29:56.709636 98.97% [DEBUG] mod_sofia.c:158 sofia/default/0902@102.220.200.133 SOFIA ROUTING
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_state_machine.c:230 sofia/default/0902@102.220.200.133 Standard ROUTING
2022-06-29 11:29:56.709636 98.97% [INFO] mod_dialplan_xml.c:639 Processing 0902 <0902>->0000 in context default
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes')
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
2022-06-29 11:29:56.709636 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] Dialed number : 0000
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT access_number FROM accessnumber WHERE access_number = '0000' AND status=0 limit 1
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Generated XML:
<?xml version="1.0" encoding="UTF-8" standalone="no"?>
<document type="freeswitch/xml">
<section name="dialplan" description="ASTPP Dialplan">
<context name="default">
<extension name="0000">
<condition field="destination_number" expression="0000">
<action application="log" data="INFO ASTPP - Calling Card Call"/>
<action application="answer"/>
<action application="sleep" data="2000"/>
<action application="lua" data="astpp-callingcards.lua"/>
</condition>
</extension>
</context>
</section>
</document>
Dialplan: sofia/default/0902@102.220.200.133 parsing [default->0000] continue=false
Dialplan: sofia/default/0902@102.220.200.133 Regex (PASS) [0000] destination_number(0000) =~ /0000/ break=on-false
Dialplan: sofia/default/0902@102.220.200.133 Action log(INFO ASTPP - Calling Card Call) 
Dialplan: sofia/default/0902@102.220.200.133 Action answer() 
Dialplan: sofia/default/0902@102.220.200.133 Action sleep(2000) 
Dialplan: sofia/default/0902@102.220.200.133 Action lua(astpp-callingcards.lua) 
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_state_machine.c:281 (sofia/default/0902@102.220.200.133) State Change CS_ROUTING -> CS_EXECUTE
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_state_machine.c:640 (sofia/default/0902@102.220.200.133) State ROUTING going to sleep
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_EXECUTE (Cur 1 Tot 706)
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_state_machine.c:647 (sofia/default/0902@102.220.200.133) State EXECUTE
2022-06-29 11:29:56.709636 98.97% [DEBUG] mod_sofia.c:213 sofia/default/0902@102.220.200.133 SOFIA EXECUTE
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_state_machine.c:323 sofia/default/0902@102.220.200.133 Standard EXECUTE
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 log(INFO ASTPP - Calling Card Call)
2022-06-29 11:29:56.709636 98.97% [INFO] mod_dptools.c:1879 ASTPP - Calling Card Call
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 answer()
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:8777 AUDIO RTP [sofia/default/0902@102.220.200.133] 102.220.200.133 port 26588 -> 102.220.201.145 port 16538 codec: 0 ms: 30
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_rtp.c:4619 Starting timer [soft] 240 bytes per 30ms
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:9089 sofia/default/0902@102.220.200.133 Set 2833 dtmf send payload to 101
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:9096 sofia/default/0902@102.220.200.133 Set 2833 dtmf receive payload to 101
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:9119 sofia/default/0902@102.220.200.133 Set rtp dtmf delay to 40
2022-06-29 11:29:56.709636 98.97% [DEBUG] mod_sofia.c:913 Local SDP sofia/default/0902@102.220.200.133:
v=0
o=FreeSWITCH 1656464808 1656464809 IN IP4 102.220.200.133
s=FreeSWITCH
c=IN IP4 102.220.200.133
t=0 0
m=audio 26588 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:30
a=sendrecv

2022-06-29 11:29:56.709636 98.97% [NOTICE] mod_dptools.c:1419 Channel [sofia/default/0902@102.220.200.133] has been answered
2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_channel.c:3950 (sofia/default/0902@102.220.200.133) Callstate Change RINGING -> ACTIVE
2022-06-29 11:29:56.709636 98.97% [DEBUG] sofia.c:7499 Channel sofia/default/0902@102.220.200.133 entering state [completed][200]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 sleep(2000)
2022-06-29 11:29:56.769690 98.97% [DEBUG] sofia.c:7499 Channel sofia/default/0902@102.220.200.133 entering state [ready][200]
2022-06-29 11:29:56.809690 98.97% [DEBUG] switch_rtp.c:7934 Correct audio ip/port confirmed.
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 lua(astpp-callingcards.lua)
2022-06-29 11:29:58.729695 98.93% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes')
2022-06-29 11:29:58.729695 98.93% [NOTICE] switch_cpp.cpp:1465 [ASTPP] SECTION 
2022-06-29 11:29:58.749615 98.93% [DEBUG] switch_core_file.c:444 File /var/www/html/astpp/upload/astpp-welcome.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:29:58.749615 98.93% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:30:00.529694 98.93% [DEBUG] switch_ivr_play_say.c:2001 done playing file /var/www/html/astpp/upload/astpp-welcome.wav
2022-06-29 11:30:00.529694 98.93% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-accountnum.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:30:00.529694 98.93% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:30:03.529689 98.33% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-accountnum.wav
2022-06-29 11:30:03.949694 98.23% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:1200
2022-06-29 11:30:03.949694 98.23% [INFO] switch_channel.c:527 RECV DTMF 1:1200
2022-06-29 11:30:04.309699 98.23% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 2:800
2022-06-29 11:30:04.309699 98.23% [INFO] switch_channel.c:527 RECV DTMF 2:800
2022-06-29 11:30:04.749690 98.23% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:1136
2022-06-29 11:30:04.749690 98.23% [INFO] switch_channel.c:527 RECV DTMF 7:1136
2022-06-29 11:30:05.049646 98.23% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:1296
2022-06-29 11:30:05.049646 98.23% [INFO] switch_channel.c:527 RECV DTMF 7:1296
2022-06-29 11:30:05.469695 98.23% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:1536
2022-06-29 11:30:05.469695 98.23% [INFO] switch_channel.c:527 RECV DTMF 1:1536
2022-06-29 11:30:05.949669 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 8:1200
2022-06-29 11:30:05.949669 98.07% [INFO] switch_channel.c:527 RECV DTMF 8:1200
2022-06-29 11:30:06.349646 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF #:1200
2022-06-29 11:30:06.349646 98.07% [INFO] switch_channel.c:527 RECV DTMF #:1200
2022-06-29 11:30:06.349646 98.07% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Got DTMF digits: 127718
2022-06-29 11:30:06.349646 98.07% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT *,(select currencyrate from currency where id=currency_id) as currencyrate FROM accounts WHERE number = "127718" AND status=0 AND deleted=0 limit 1
2022-06-29 11:30:06.349646 98.07% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-pleasepin.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:30:06.349646 98.07% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:30:09.009648 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 6:1280
2022-06-29 11:30:09.009648 98.07% [INFO] switch_channel.c:527 RECV DTMF 6:1280
2022-06-29 11:30:09.009648 98.07% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-pleasepin.wav
2022-06-29 11:30:09.369694 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 3:896
2022-06-29 11:30:09.369694 98.07% [INFO] switch_channel.c:527 RECV DTMF 3:896
2022-06-29 11:30:09.829700 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:960
2022-06-29 11:30:09.829700 98.07% [INFO] switch_channel.c:527 RECV DTMF 1:960
2022-06-29 11:30:10.149694 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 4:960
2022-06-29 11:30:10.149694 98.07% [INFO] switch_channel.c:527 RECV DTMF 4:960
2022-06-29 11:30:10.629699 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF #:1456
2022-06-29 11:30:10.629699 98.07% [INFO] switch_channel.c:527 RECV DTMF #:1456
2022-06-29 11:30:10.629699 98.07% [DEBUG] switch_cpp.cpp:1465 [ASTPP] We recieved a pin : 6314
2022-06-29 11:30:10.629699 98.07% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [validate_card_usage] Query :SELECT DATE_FORMAT('2032-06-21 10:11:08' , '%Y%m%d%H%i%s') AS expiry
2022-06-29 11:30:10.629699 98.07% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [validate_card_usage] Query :SELECT DATE_FORMAT('2022-06-29 08:30:10' , '%Y%m%d%H%i%s') AS expiry
2022-06-29 11:30:10.649624 98.03% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [Accountcode : 127718]
2022-06-29 11:30:10.649624 98.03% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-this-card-has-a-balance-of.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:30:10.649624 98.03% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:30:11.949699 98.03% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-this-card-has-a-balance-of.wav
2022-06-29 11:30:11.949699 98.03% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [Play Amount First Part] Query :5000
2022-06-29 11:30:11.949699 98.03% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [Play Amount Second Part] Query :00
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 say(en number pronounced 5000)
2022-06-29 11:30:11.969630 98.03% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:30:13.189699 97.93% [DEBUG] switch_ivr_play_say.c:2001 done playing file file_string://digits/5.wav!digits/thousand.wav
2022-06-29 11:30:13.189699 97.93% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-point.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:30:13.189699 97.93% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:30:13.749697 97.93% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-point.wav
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 say(en number pronounced 00)
2022-06-29 11:30:13.789625 97.93% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:30:14.529690 97.93% [DEBUG] switch_ivr_play_say.c:2001 done playing file file_string://digits/0.wav
2022-06-29 11:30:14.549632 97.93% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-phonenum.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:30:14.549632 97.93% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:30:18.249691 97.93% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-phonenum.wav
2022-06-29 11:30:30.229699 98.17% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [690@102.220.200.133] from ip 156.146.45.104
2022-06-29 11:30:30.909694 98.17% [WARNING] sofia_reg.c:3223 Can't find user [690@102.220.200.133] from 156.146.45.104
You must define a domain called '102.220.200.133' in your directory and add a user with the id="690" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:30:30.909694 98.17% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [690@102.220.200.133] from ip 156.146.45.104
2022-06-29 11:30:33.309650 98.73% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-badphone.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:30:33.309650 98.73% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:30:34.729698 98.87% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-badphone.wav
2022-06-29 11:30:34.729698 98.87% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-phonenum.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:30:34.729698 98.87% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:30:37.029694 99.10% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 9:1184
2022-06-29 11:30:37.029694 99.10% [INFO] switch_channel.c:527 RECV DTMF 9:1184
2022-06-29 11:30:37.029694 99.10% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-phonenum.wav
2022-06-29 11:30:37.449690 99.10% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 0:1280
2022-06-29 11:30:37.449690 99.10% [INFO] switch_channel.c:527 RECV DTMF 0:1280
2022-06-29 11:30:37.749690 99.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:624
2022-06-29 11:30:37.749690 99.07% [INFO] switch_channel.c:527 RECV DTMF 7:624
2022-06-29 11:30:37.989694 99.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:640
2022-06-29 11:30:37.989694 99.07% [INFO] switch_channel.c:527 RECV DTMF 7:640
2022-06-29 11:30:38.329695 99.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 9:960
2022-06-29 11:30:38.329695 99.07% [INFO] switch_channel.c:527 RECV DTMF 9:960
2022-06-29 11:30:38.709699 99.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 2:1184
2022-06-29 11:30:38.709699 99.07% [INFO] switch_channel.c:527 RECV DTMF 2:1184
2022-06-29 11:30:39.129695 99.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 0:1440
2022-06-29 11:30:39.129695 99.07% [INFO] switch_channel.c:527 RECV DTMF 0:1440
2022-06-29 11:30:39.429699 99.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 5:960
2022-06-29 11:30:39.429699 99.07% [INFO] switch_channel.c:527 RECV DTMF 5:960
2022-06-29 11:30:39.569690 99.07% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [673@102.220.200.133] from ip 93.190.138.235
2022-06-29 11:30:39.809691 98.97% [WARNING] sofia_reg.c:3223 Can't find user [673@102.220.200.133] from 93.190.138.235
You must define a domain called '102.220.200.133' in your directory and add a user with the id="673" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:30:39.809691 98.97% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [673@102.220.200.133] from ip 93.190.138.235
2022-06-29 11:30:39.829627 98.97% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 0:1120
2022-06-29 11:30:39.829627 98.97% [INFO] switch_channel.c:527 RECV DTMF 0:1120
2022-06-29 11:30:40.189691 98.97% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 9:1120
2022-06-29 11:30:40.189691 98.97% [INFO] switch_channel.c:527 RECV DTMF 9:1120
2022-06-29 11:30:40.549694 98.97% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:1200
2022-06-29 11:30:40.549694 98.97% [INFO] switch_channel.c:527 RECV DTMF 7:1200
2022-06-29 11:30:40.929695 98.97% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF #:1360
2022-06-29 11:30:40.929695 98.97% [INFO] switch_channel.c:527 RECV DTMF #:1360
2022-06-29 11:30:40.929695 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] [CHECK_destination] Dialed destination number :90779205097
2022-06-29 11:30:40.929695 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Account Information ===================
2022-06-29 11:30:40.929695 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] User id : 17
2022-06-29 11:30:40.929695 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] Account code : 127718
2022-06-29 11:30:40.929695 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] Balance : 5000
2022-06-29 11:30:40.929695 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] Type : 0 [0:prepaid,1:postpaid]
2022-06-29 11:30:40.929695 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] Ratecard id : 4
2022-06-29 11:30:40.929695 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] ========================================================
2022-06-29 11:30:40.929695 98.97% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CHECK_BLOCKED_PREFIX] Query :SELECT * FROM block_patterns WHERE (blocked_patterns = '^90779205097.*' OR blocked_patterns = '^9077920509.*' OR blocked_patterns = '^907792050.*' OR blocked_patterns = '^90779205.*' OR blocked_patterns = '^9077920.*' OR blocked_patterns = '^907792.*' OR blocked_patterns = '^90779.*' OR blocked_patterns = '^9077.*' OR blocked_patterns = '^907.*' OR blocked_patterns = '^90.*' OR blocked_patterns = '^9.*' OR blocked_patterns ='--') AND accountid = 17 limit 1 
2022-06-29 11:30:40.949626 98.97% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_PACKAGE_INFO] Query :SELECT *,P.id as package_id,P.product_id as product_id FROM packages_view as P inner join package_patterns as PKGPTR on P.product_id = PKGPTR.product_id WHERE (patterns = '^90779205097.*' OR patterns = '^9077920509.*' OR patterns = '^907792050.*' OR patterns = '^90779205.*' OR patterns = '^9077920.*' OR patterns = '^907792.*' OR patterns = '^90779.*' OR patterns = '^9077.*' OR patterns = '^907.*' OR patterns = '^90.*' OR patterns = '^9.*' OR patterns ='--') AND accountid = 17 ORDER BY LENGTH(PKGPTR.patterns) DESC
2022-06-29 11:30:40.949626 98.97% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 4 AND status = 0
2022-06-29 11:30:40.949626 98.97% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_RATES] call_direction :
2022-06-29 11:30:40.949626 98.97% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_RATES] Query :SELECT * FROM routes WHERE (pattern = '^90779205097.*' OR pattern = '^9077920509.*' OR pattern = '^907792050.*' OR pattern = '^90779205.*' OR pattern = '^9077920.*' OR pattern = '^907792.*' OR pattern = '^90779.*' OR pattern = '^9077.*' OR pattern = '^907.*' OR pattern = '^90.*' OR pattern = '^9.*' OR pattern ='--') AND status = 0 AND (pricelist_id = 4 OR accountid=17)  ORDER BY accountid DESC,LENGTH(pattern) DESC,cost DESC LIMIT 1
2022-06-29 11:30:40.949626 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] call_direction:::::: 
2022-06-29 11:30:40.949626 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Rates Information ===================
2022-06-29 11:30:40.949626 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] ID : 8
2022-06-29 11:30:40.949626 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] Connectcost : 0.00000
2022-06-29 11:30:40.949626 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] Includedseconds : 0
2022-06-29 11:30:40.949626 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] Cost : 220.00000
2022-06-29 11:30:40.949626 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] comment : Uganda
2022-06-29 11:30:40.949626 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] Country Id : 197
2022-06-29 11:30:40.949626 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] Accid : 17
2022-06-29 11:30:40.949626 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] Trunk ID: 3
2022-06-29 11:30:40.949626 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] Routing type: 
2022-06-29 11:30:40.949626 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] ================================================================
2022-06-29 11:30:40.949626 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] [FIND_MAXLENGTH] Your5000 balance Accountid 17 !!!
2022-06-29 11:30:40.949626 98.97% [NOTICE] switch_cpp.cpp:1465 [ASTPP] 22 Minutes
2022-06-29 11:30:40.949626 98.97% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [SAY_TIMELIMIT] MINUTES 22
2022-06-29 11:30:40.949626 98.97% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-this-call-will-last.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:30:40.949626 98.97% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:30:42.129694 98.97% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-this-call-will-last.wav
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 say(en number pronounced 22)
2022-06-29 11:30:42.149632 98.97% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:30:43.249640 99.03% [DEBUG] switch_ivr_play_say.c:2001 done playing file file_string://digits/20.wav!digits/2.wav
2022-06-29 11:30:43.249640 99.03% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-minutes.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:30:43.249640 99.03% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:30:43.869690 99.03% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-minutes.wav
2022-06-29 11:30:43.869690 99.03% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_CARRIER_RATES] Query :SELECT TK.id as trunk_id,TK.name as trunk_name,TK.codec,GW.name as path,GW.dialplan_variable,TK.provider_id,TR.init_inc,TK.status,TK.maxchannels,TK.cps,TK.leg_timeout,TR.pattern,TR.id as outbound_route_id,TR.connectcost,TR.comment,TR.includedseconds,TR.cost,TR.inc,TR.prepend,TR.strip,(select name from gateways where status=0 AND id = TK.failover_gateway_id) as path1,(select name from gateways where status=0 AND id = TK.failover_gateway_id1) as path2 FROM outbound_routes as TR,trunks as TK,gateways as GW WHERE GW.status=0 AND GW.id= TK.gateway_id AND TK.status=0 AND TK.id= TR.trunk_id AND (pattern = '^90779205097.*' OR pattern = '^9077920509.*' OR pattern = '^907792050.*' OR pattern = '^90779205.*' OR pattern = '^9077920.*' OR pattern = '^907792.*' OR pattern = '^90779.*' OR pattern = '^9077.*' OR pattern = '^907.*' OR pattern = '^90.*' OR pattern = '^9.*' OR pattern ='--') AND TR.status = 0  AND TR.trunk_id IN (3)  ORDER by LENGTH (pattern) DESC,TR.cost ASC,TR.precedence ASC, TK.precedence
2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Termination Rates Information ===================
2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] ID : 6
2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] Code : ^90.*
2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] Destination : Uganda
2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] Connectcost : 0.00000
2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] Free Seconds : 0
2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] Prefix : ^90.*
2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] Strip : 9
2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] Termination rate id : 3
2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] Gateway name : MTN
2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] Failover gateway : 
2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] Vendor id : 18
2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] Max channels : 0
2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] trunk_name : MTN
2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] =================================================================
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(call_processed=internal)
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [call_processed]=[internal]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(callstart=2022-06-29 08:30:43)
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [callstart]=[2022-06-29 08:30:43]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(originated_destination_number=90779205097)
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [originated_destination_number]=[90779205097]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(effective_destination_number=90779205097)
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [effective_destination_number]=[90779205097]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(continue_on_fail=true)
2022-06-29 11:30:43.889631 99.03% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [continue_on_fail]=[true]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(hangup_after_bridge=true)
2022-06-29 11:30:43.889631 99.03% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [hangup_after_bridge]=[true]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(account_id=17)
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [account_id]=[17]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(account_type=0)
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [account_type]=[0]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(resellerid=0)
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [resellerid]=[0]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(parent_id=0)
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [parent_id]=[0]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(accountcode=127718)
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [accountcode]=[127718]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(call_direction=outbound)
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [call_direction]=[outbound]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(calltype=CALLINGCARD)
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [calltype]=[CALLINGCARD]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(origination_rates=ID:8|CODE:^907.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:1|COST:220.00000|INC:60|INITIALBLOCK:60|RATEGROUP:4|MARKUP:0|CI:197|ACCID:17)
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [origination_rates]=[ID:8|CODE:^907.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:1|COST:220.00000|INC:60|INITIALBLOCK:60|RATEGROUP:4|MARKUP:0|CI:197|ACCID:17]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(execute_on_answer=sched_hangup +1320)
2022-06-29 11:30:43.889631 99.03% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [execute_on_answer]=[sched_hangup +1320]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(process_cdr=true)
2022-06-29 11:30:43.889631 99.03% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [process_cdr]=[true]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 sched_hangup(+1320)
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_scheduler.c:263 Added task 5 switch_ivr_schedule_hangup (c71261ca-c074-4061-a372-aa03d5185441) to run at 1656492763
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_OVERRIDE_CALLERID] Query :SELECT callerid_name as cid_name,callerid_number as cid_number,accountid FROM accounts_callerid WHERE accountid = 17 AND status=0 LIMIT 1
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(original_caller_id_name=0902)
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [original_caller_id_name]=[0902]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(original_caller_id_number=0902)
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [original_caller_id_number]=[0902]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(presence_data=x|||Dorcas(127718)|||^907.* // Uganda // 220.00000|||MTN // ^90.* // Uganda // 220.00000|||CC)
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [presence_data]=[x|||Dorcas(127718)|||^907.* // Uganda // 220.00000|||MTN // ^90.* // Uganda // 220.00000|||CC]
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,out_caller_id_terminate,number_terminate FROM localization WHERE id=(SELECT localization_id from accounts where id = 18) AND status=0 limit 1 
2022-06-29 11:30:43.889631 99.03% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [DONUMBERTRANSLATION] Before Localization CLI/DST : 90779205097
2022-06-29 11:30:43.889631 99.03% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [DONUMBERTRANSLATION] After Localization CLI/DST : 0779205097
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(termination_rates=ID:6|CODE:^90.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:220.00000|INC:60|TRUNK:3|PROVIDER:18)
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [termination_rates]=[ID:6|CODE:^90.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:220.00000|INC:60|TRUNK:3|PROVIDER:18]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(trunk_id=3)
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [trunk_id]=[3]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(provider_id=18)
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [provider_id]=[18]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(hangup_after_bridge=false)
2022-06-29 11:30:43.889631 99.03% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [hangup_after_bridge]=[false]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(absolute_codec_string=PCMA,G729,PCMA)
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [absolute_codec_string]=[PCMA,G729,PCMA]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 bridge([leg_timeout=0]sofia/gateway/MTN/0779205097)
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1954 (sofia/default/0902@102.220.200.133) Callstate Change ACTIVE -> RING_WAIT
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [call_processed]=[internal] to event
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [callstart]=[2022-06-29 08:30:43] to event
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [originated_destination_number]=[90779205097] to event
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [effective_destination_number]=[90779205097] to event
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [account_id]=[17] to event
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [account_type]=[0] to event
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [resellerid]=[0] to event
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [parent_id]=[0] to event
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [accountcode]=[127718] to event
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [call_direction]=[outbound] to event
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [calltype]=[CALLINGCARD] to event
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [origination_rates]=[ID:8|CODE:^907.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:1|COST:220.00000|INC:60|INITIALBLOCK:60|RATEGROUP:4|MARKUP:0|CI:197|ACCID:17] to event
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [original_caller_id_name]=[0902] to event
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [original_caller_id_number]=[0902] to event
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [presence_data]=[x|||Dorcas(127718)|||^907.* // Uganda // 220.00000|||MTN // ^90.* // Uganda // 220.00000|||CC] to event
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [termination_rates]=[ID:6|CODE:^90.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:220.00000|INC:60|TRUNK:3|PROVIDER:18] to event
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [trunk_id]=[3] to event
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [provider_id]=[18] to event
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [absolute_codec_string]=[PCMA,G729,PCMA] to event
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_ivr_originate.c:2843 Parsing session specific variables
2022-06-29 11:30:43.889631 99.03% [NOTICE] switch_channel.c:1123 New Channel sofia/default/0779205097 [f9d92969-278e-4af7-9ec5-da3db01f8cda]
2022-06-29 11:30:43.889631 99.03% [DEBUG] mod_sofia.c:5121 (sofia/default/0779205097) State Change CS_NEW -> CS_INIT
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0779205097) Running State Change CS_INIT (Cur 2 Tot 707)
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:624 (sofia/default/0779205097) State INIT
2022-06-29 11:30:43.889631 99.03% [DEBUG] mod_sofia.c:97 sofia/default/0779205097 SOFIA INIT
2022-06-29 11:30:43.889631 99.03% [INFO] sofia_glue.c:1651 sofia/default/0779205097 sending invite call-id: (null)
2022-06-29 11:30:43.889631 99.03% [DEBUG] sofia_glue.c:1654 sofia/default/0779205097 sending invite version: 1.10.7 -release-19-883d2cb662 64bit
Local SDP:
v=0
o=FreeSWITCH 1656463215 1656463216 IN IP4 102.220.200.133
s=FreeSWITCH
c=IN IP4 102.220.200.133
t=0 0
m=audio 28228 RTP/AVP 8 18 101
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv

2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:40 sofia/default/0779205097 Standard INIT
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:48 (sofia/default/0779205097) State Change CS_INIT -> CS_ROUTING
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:624 (sofia/default/0779205097) State INIT going to sleep
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0779205097) Running State Change CS_ROUTING (Cur 2 Tot 707)
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:640 (sofia/default/0779205097) State ROUTING
2022-06-29 11:30:43.889631 99.03% [DEBUG] mod_sofia.c:158 sofia/default/0779205097 SOFIA ROUTING
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_ivr_originate.c:67 (sofia/default/0779205097) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:640 (sofia/default/0779205097) State ROUTING going to sleep
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0779205097) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 707)
2022-06-29 11:30:43.889631 99.03% [DEBUG] sofia.c:7499 Channel sofia/default/0779205097 entering state [calling][0]
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:659 (sofia/default/0779205097) State CONSUME_MEDIA
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:659 (sofia/default/0779205097) State CONSUME_MEDIA going to sleep
2022-06-29 11:30:43.889631 99.03% [DEBUG] sofia.c:7499 Channel sofia/default/0779205097 entering state [terminated][503]
2022-06-29 11:30:43.889631 99.03% [NOTICE] sofia.c:8738 Hangup sofia/default/0779205097 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE]
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0779205097) Running State Change CS_HANGUP (Cur 2 Tot 707)
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:844 (sofia/default/0779205097) Callstate Change DOWN -> HANGUP
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:846 (sofia/default/0779205097) State HANGUP
2022-06-29 11:30:43.889631 99.03% [DEBUG] mod_sofia.c:468 Channel sofia/default/0779205097 hanging up, cause: NORMAL_TEMPORARY_FAILURE
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE]
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:59 sofia/default/0779205097 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:846 (sofia/default/0779205097) State HANGUP going to sleep
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:616 (sofia/default/0779205097) State Change CS_HANGUP -> CS_REPORTING
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0779205097) Running State Change CS_REPORTING (Cur 2 Tot 707)
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:932 (sofia/default/0779205097) State REPORTING
2022-06-29 11:30:43.889631 99.03% [INFO] mod_json_cdr.c:271 Process [f9d92969-278e-4af7-9ec5-da3db01f8cda.cdr.json]
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:2178 (sofia/default/0902@102.220.200.133) Callstate Change RING_WAIT -> ACTIVE
2022-06-29 11:30:43.889631 99.03% [INFO] mod_dptools.c:3653 Originate Failed.  Cause: NORMAL_TEMPORARY_FAILURE
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-callingcard-menu.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:30:43.989668 99.03% [DEBUG] switch_core_state_machine.c:168 sofia/default/0779205097 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
2022-06-29 11:30:43.989668 99.03% [DEBUG] switch_core_state_machine.c:932 (sofia/default/0779205097) State REPORTING going to sleep
2022-06-29 11:30:43.989668 99.03% [DEBUG] switch_core_state_machine.c:607 (sofia/default/0779205097) State Change CS_REPORTING -> CS_DESTROY
2022-06-29 11:30:43.989668 99.03% [DEBUG] switch_core_session.c:1753 Session 707 (sofia/default/0779205097) Locked, Waiting on external entities
2022-06-29 11:30:43.989668 99.03% [NOTICE] switch_core_session.c:1771 Session 707 (sofia/default/0779205097) Ended
2022-06-29 11:30:43.989668 99.03% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/0779205097 [CS_DESTROY]
2022-06-29 11:30:43.989668 99.03% [DEBUG] switch_core_state_machine.c:735 (sofia/default/0779205097) Running State Change CS_DESTROY (Cur 1 Tot 707)
2022-06-29 11:30:43.989668 99.03% [DEBUG] switch_core_state_machine.c:745 (sofia/default/0779205097) State DESTROY
2022-06-29 11:30:43.989668 99.03% [DEBUG] mod_sofia.c:379 sofia/default/0779205097 SOFIA DESTROY
2022-06-29 11:30:43.989668 99.03% [DEBUG] switch_core_state_machine.c:175 sofia/default/0779205097 Standard DESTROY
2022-06-29 11:30:43.989668 99.03% [DEBUG] switch_core_state_machine.c:745 (sofia/default/0779205097) State DESTROY going to sleep
2022-06-29 11:30:50.049690 98.83% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-callingcard-menu.wav
2022-06-29 11:30:52.009662 98.87% [NOTICE] sofia.c:1065 Hangup sofia/default/0902@102.220.200.133 [CS_EXECUTE] [NORMAL_CLEARING]
2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Got DTMF digits: retries:0
2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Got DTMF digits: retries:1
2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Got DTMF digits: retries:2
2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_cpp.cpp:749 CoreSession::hangup
2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_cpp.cpp:1209 sofia/default/0902@102.220.200.133 destroy/unlink session from object
2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_session.c:2983 sofia/default/0902@102.220.200.133 skip receive message [PHONE_EVENT] (channel is hungup already)
2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:647 (sofia/default/0902@102.220.200.133) State EXECUTE going to sleep
2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_HANGUP (Cur 1 Tot 707)
2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:844 (sofia/default/0902@102.220.200.133) Callstate Change ACTIVE -> HANGUP
2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:846 (sofia/default/0902@102.220.200.133) State HANGUP
2022-06-29 11:30:52.009662 98.87% [DEBUG] mod_sofia.c:462 sofia/default/0902@102.220.200.133 Overriding SIP cause 480 with 503 from the other leg
2022-06-29 11:30:52.009662 98.87% [DEBUG] mod_sofia.c:468 Channel sofia/default/0902@102.220.200.133 hanging up, cause: NORMAL_CLEARING
2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:59 sofia/default/0902@102.220.200.133 Standard HANGUP, cause: NORMAL_CLEARING
2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:846 (sofia/default/0902@102.220.200.133) State HANGUP going to sleep
2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:616 (sofia/default/0902@102.220.200.133) State Change CS_HANGUP -> CS_REPORTING
2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_REPORTING (Cur 1 Tot 707)
2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:932 (sofia/default/0902@102.220.200.133) State REPORTING
2022-06-29 11:30:52.009662 98.87% [INFO] mod_json_cdr.c:271 Process [c71261ca-c074-4061-a372-aa03d5185441.cdr.json]
2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:168 sofia/default/0902@102.220.200.133 Standard REPORTING, cause: NORMAL_CLEARING
2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:932 (sofia/default/0902@102.220.200.133) State REPORTING going to sleep
2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:607 (sofia/default/0902@102.220.200.133) State Change CS_REPORTING -> CS_DESTROY
2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_session.c:1753 Session 706 (sofia/default/0902@102.220.200.133) Locked, Waiting on external entities
2022-06-29 11:30:52.009662 98.87% [NOTICE] switch_core_session.c:1771 Session 706 (sofia/default/0902@102.220.200.133) Ended
2022-06-29 11:30:52.009662 98.87% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/0902@102.220.200.133 [CS_DESTROY]
2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:735 (sofia/default/0902@102.220.200.133) Running State Change CS_DESTROY (Cur 0 Tot 707)
2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:745 (sofia/default/0902@102.220.200.133) State DESTROY
2022-06-29 11:30:52.009662 98.87% [DEBUG] mod_sofia.c:379 sofia/default/0902@102.220.200.133 SOFIA DESTROY
2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:175 sofia/default/0902@102.220.200.133 Standard DESTROY
2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:745 (sofia/default/0902@102.220.200.133) State DESTROY going to sleep
2022-06-29 11:30:52.389694 98.87% [DEBUG] switch_scheduler.c:147 Deleting task 5 switch_ivr_schedule_hangup (c71261ca-c074-4061-a372-aa03d5185441)
2022-06-29 11:31:22.409694 97.93% [NOTICE] switch_channel.c:1123 New Channel sofia/default/0902@102.220.200.133 [a5859f66-b4eb-44b9-aaeb-61a5d3692597]
2022-06-29 11:31:22.409694 97.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_NEW (Cur 1 Tot 708)
2022-06-29 11:31:22.409694 97.93% [INFO] sofia.c:10462 sofia/default/0902@102.220.200.133 receiving invite from 102.220.201.145:5060 version: 1.10.7 -release-19-883d2cb662 64bit call-id: 13a8b29b-dd6cbd60@102.220.201.145
2022-06-29 11:31:22.409694 97.93% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 102.220.201.145:0.
2022-06-29 11:31:22.409694 97.93% [WARNING] sofia_reg.c:1861 SIP auth challenge (INVITE) on sofia profile 'default' for [0000@102.220.200.133] from ip 102.220.201.145
2022-06-29 11:31:22.409694 97.93% [DEBUG] switch_core_state_machine.c:600 (sofia/default/0902@102.220.200.133) State NEW
2022-06-29 11:31:22.409694 97.93% [DEBUG] sofia.c:2419 detaching session a5859f66-b4eb-44b9-aaeb-61a5d3692597
2022-06-29 11:31:22.429690 97.93% [DEBUG] sofia.c:2532 Re-attaching to session a5859f66-b4eb-44b9-aaeb-61a5d3692597
2022-06-29 11:31:22.429690 97.93% [INFO] sofia.c:10462 sofia/default/0902@102.220.200.133 receiving invite from 102.220.201.145:5060 version: 1.10.7 -release-19-883d2cb662 64bit call-id: 13a8b29b-dd6cbd60@102.220.201.145
2022-06-29 11:31:22.429690 97.93% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 102.220.201.145:0.
2022-06-29 11:31:22.449641 97.93% [DEBUG] sofia.c:7499 Channel sofia/default/0902@102.220.200.133 entering state [received][100]
2022-06-29 11:31:22.449641 97.93% [DEBUG] sofia.c:7509 Remote SDP:
v=0
o=- 14914752 14914752 IN IP4 102.220.201.145
s=-
c=IN IP4 102.220.201.145
t=0 0
m=audio 16384 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:30

2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:30:64000:1]/[PCMA:8:8000:20:64000:1]
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:30:64000:1]/[PCMU:0:8000:20:64000:1]
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5686 Audio Codec Compare [PCMU:0:8000:20:64000:1] is saved as a near-match
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-32:2:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-32:2:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:30:64000:1]/[PCMA:8:8000:20:64000:1]
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5686 Audio Codec Compare [PCMA:8:8000:20:64000:1] is saved as a near-match
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:30:64000:1]/[PCMU:0:8000:20:64000:1]
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G722:9:8000:30:64000:1]/[PCMA:8:8000:20:64000:1]
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G722:9:8000:30:64000:1]/[PCMU:0:8000:20:64000:1]
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729a:18:8000:30:8000:1]/[PCMA:8:8000:20:64000:1]
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729a:18:8000:30:8000:1]/[PCMU:0:8000:20:64000:1]
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-40:96:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-40:96:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-24:97:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-24:97:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-16:98:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-16:98:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5566 Set telephone-event payload to 101@8000
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5757 Substituting codec PCMU@30i@8000h@1c
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:3870 Set Codec sofia/default/0902@102.220.200.133 PCMU/8000 30 ms 240 samples 64000 bits 1 channels
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_codec.c:111 sofia/default/0902@102.220.200.133 Original read codec set to PCMU:0
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5915 Set telephone-event payload to 101@8000
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5973 sofia/default/0902@102.220.200.133 Set 2833 dtmf send payload to 101 recv payload to 101
2022-06-29 11:31:22.449641 97.93% [DEBUG] sofia.c:7933 (sofia/default/0902@102.220.200.133) State Change CS_NEW -> CS_INIT
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_INIT (Cur 1 Tot 708)
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_state_machine.c:624 (sofia/default/0902@102.220.200.133) State INIT
2022-06-29 11:31:22.449641 97.93% [DEBUG] mod_sofia.c:97 sofia/default/0902@102.220.200.133 SOFIA INIT
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_state_machine.c:40 sofia/default/0902@102.220.200.133 Standard INIT
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_state_machine.c:48 (sofia/default/0902@102.220.200.133) State Change CS_INIT -> CS_ROUTING
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_state_machine.c:624 (sofia/default/0902@102.220.200.133) State INIT going to sleep
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_ROUTING (Cur 1 Tot 708)
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_channel.c:2380 (sofia/default/0902@102.220.200.133) Callstate Change DOWN -> RINGING
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_state_machine.c:640 (sofia/default/0902@102.220.200.133) State ROUTING
2022-06-29 11:31:22.449641 97.93% [DEBUG] mod_sofia.c:158 sofia/default/0902@102.220.200.133 SOFIA ROUTING
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_state_machine.c:230 sofia/default/0902@102.220.200.133 Standard ROUTING
2022-06-29 11:31:22.449641 97.93% [INFO] mod_dialplan_xml.c:639 Processing 0902 <0902>->0000 in context default
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes')
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
2022-06-29 11:31:22.449641 97.93% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] Dialed number : 0000
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT access_number FROM accessnumber WHERE access_number = '0000' AND status=0 limit 1
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Generated XML:
<?xml version="1.0" encoding="UTF-8" standalone="no"?>
<document type="freeswitch/xml">
<section name="dialplan" description="ASTPP Dialplan">
<context name="default">
<extension name="0000">
<condition field="destination_number" expression="0000">
<action application="log" data="INFO ASTPP - Calling Card Call"/>
<action application="answer"/>
<action application="sleep" data="2000"/>
<action application="lua" data="astpp-callingcards.lua"/>
</condition>
</extension>
</context>
</section>
</document>
Dialplan: sofia/default/0902@102.220.200.133 parsing [default->0000] continue=false
Dialplan: sofia/default/0902@102.220.200.133 Regex (PASS) [0000] destination_number(0000) =~ /0000/ break=on-false
Dialplan: sofia/default/0902@102.220.200.133 Action log(INFO ASTPP - Calling Card Call) 
Dialplan: sofia/default/0902@102.220.200.133 Action answer() 
Dialplan: sofia/default/0902@102.220.200.133 Action sleep(2000) 
Dialplan: sofia/default/0902@102.220.200.133 Action lua(astpp-callingcards.lua) 
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_state_machine.c:281 (sofia/default/0902@102.220.200.133) State Change CS_ROUTING -> CS_EXECUTE
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_state_machine.c:640 (sofia/default/0902@102.220.200.133) State ROUTING going to sleep
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_EXECUTE (Cur 1 Tot 708)
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_state_machine.c:647 (sofia/default/0902@102.220.200.133) State EXECUTE
2022-06-29 11:31:22.449641 97.93% [DEBUG] mod_sofia.c:213 sofia/default/0902@102.220.200.133 SOFIA EXECUTE
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_state_machine.c:323 sofia/default/0902@102.220.200.133 Standard EXECUTE
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 log(INFO ASTPP - Calling Card Call)
2022-06-29 11:31:22.449641 97.93% [INFO] mod_dptools.c:1879 ASTPP - Calling Card Call
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 answer()
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:8777 AUDIO RTP [sofia/default/0902@102.220.200.133] 102.220.200.133 port 24520 -> 102.220.201.145 port 16384 codec: 0 ms: 30
2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_rtp.c:4619 Starting timer [soft] 240 bytes per 30ms
2022-06-29 11:31:22.469613 97.93% [DEBUG] switch_core_media.c:9089 sofia/default/0902@102.220.200.133 Set 2833 dtmf send payload to 101
2022-06-29 11:31:22.469613 97.93% [DEBUG] switch_core_media.c:9096 sofia/default/0902@102.220.200.133 Set 2833 dtmf receive payload to 101
2022-06-29 11:31:22.469613 97.93% [DEBUG] switch_core_media.c:9119 sofia/default/0902@102.220.200.133 Set rtp dtmf delay to 40
2022-06-29 11:31:22.469613 97.93% [DEBUG] mod_sofia.c:913 Local SDP sofia/default/0902@102.220.200.133:
v=0
o=FreeSWITCH 1656466962 1656466963 IN IP4 102.220.200.133
s=FreeSWITCH
c=IN IP4 102.220.200.133
t=0 0
m=audio 24520 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:30
a=sendrecv

2022-06-29 11:31:22.469613 97.93% [NOTICE] mod_dptools.c:1419 Channel [sofia/default/0902@102.220.200.133] has been answered
2022-06-29 11:31:22.469613 97.93% [DEBUG] switch_channel.c:3950 (sofia/default/0902@102.220.200.133) Callstate Change RINGING -> ACTIVE
2022-06-29 11:31:22.469613 97.93% [DEBUG] sofia.c:7499 Channel sofia/default/0902@102.220.200.133 entering state [completed][200]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 sleep(2000)
2022-06-29 11:31:22.509684 97.93% [DEBUG] sofia.c:7499 Channel sofia/default/0902@102.220.200.133 entering state [ready][200]
2022-06-29 11:31:22.569691 97.93% [DEBUG] switch_rtp.c:7934 Correct audio ip/port confirmed.
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 lua(astpp-callingcards.lua)
2022-06-29 11:31:24.489650 97.93% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes')
2022-06-29 11:31:24.489650 97.93% [NOTICE] switch_cpp.cpp:1465 [ASTPP] SECTION 
2022-06-29 11:31:24.489650 97.93% [DEBUG] switch_core_file.c:444 File /var/www/html/astpp/upload/astpp-welcome.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:31:24.489650 97.93% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:31:26.269653 98.10% [DEBUG] switch_ivr_play_say.c:2001 done playing file /var/www/html/astpp/upload/astpp-welcome.wav
2022-06-29 11:31:26.269653 98.10% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-accountnum.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:31:26.269653 98.10% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:31:28.069671 98.30% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [687@102.220.200.133] from ip 138.199.60.166
2022-06-29 11:31:28.489694 98.30% [WARNING] sofia_reg.c:3223 Can't find user [687@102.220.200.133] from 138.199.60.166
You must define a domain called '102.220.200.133' in your directory and add a user with the id="687" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:31:28.489694 98.30% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [687@102.220.200.133] from ip 138.199.60.166
2022-06-29 11:31:28.969694 98.37% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:1360
2022-06-29 11:31:28.969694 98.37% [INFO] switch_channel.c:527 RECV DTMF 1:1360
2022-06-29 11:31:28.969694 98.37% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-accountnum.wav
2022-06-29 11:31:29.329695 98.37% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 2:1040
2022-06-29 11:31:29.329695 98.37% [INFO] switch_channel.c:527 RECV DTMF 2:1040
2022-06-29 11:31:29.689696 98.40% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:800
2022-06-29 11:31:29.689696 98.40% [INFO] switch_channel.c:527 RECV DTMF 7:800
2022-06-29 11:31:29.949696 98.40% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:960
2022-06-29 11:31:29.949696 98.40% [INFO] switch_channel.c:527 RECV DTMF 7:960
2022-06-29 11:31:30.289700 98.40% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:880
2022-06-29 11:31:30.289700 98.40% [INFO] switch_channel.c:527 RECV DTMF 1:880
2022-06-29 11:31:30.349691 98.40% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [692@102.220.200.133] from ip 213.109.151.9
2022-06-29 11:31:30.429691 98.40% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 91.240.243.18
2022-06-29 11:31:30.549689 98.40% [WARNING] sofia_reg.c:3223 Can't find user [692@102.220.200.133] from 213.109.151.9
You must define a domain called '102.220.200.133' in your directory and add a user with the id="692" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:31:30.549689 98.40% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [692@102.220.200.133] from ip 213.109.151.9
2022-06-29 11:31:30.649694 98.37% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 8:960
2022-06-29 11:31:30.649694 98.37% [INFO] switch_channel.c:527 RECV DTMF 8:960
2022-06-29 11:31:30.709664 98.37% [WARNING] sofia_reg.c:3223 Can't find user [769@102.220.200.133] from 91.240.243.18
You must define a domain called '102.220.200.133' in your directory and add a user with the id="769" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:31:30.709664 98.37% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 91.240.243.18
2022-06-29 11:31:31.029692 98.37% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF #:1040
2022-06-29 11:31:31.029692 98.37% [INFO] switch_channel.c:527 RECV DTMF #:1040
2022-06-29 11:31:31.049667 98.37% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Got DTMF digits: 127718
2022-06-29 11:31:31.049667 98.37% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT *,(select currencyrate from currency where id=currency_id) as currencyrate FROM accounts WHERE number = "127718" AND status=0 AND deleted=0 limit 1
2022-06-29 11:31:31.049667 98.37% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-pleasepin.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:31:31.049667 98.37% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:31:33.709693 99.03% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 6:1360
2022-06-29 11:31:33.709693 99.03% [INFO] switch_channel.c:527 RECV DTMF 6:1360
2022-06-29 11:31:33.709693 99.03% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-pleasepin.wav
2022-06-29 11:31:34.009693 99.03% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 3:720
2022-06-29 11:31:34.009693 99.03% [INFO] switch_channel.c:527 RECV DTMF 3:720
2022-06-29 11:31:34.389696 99.03% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:880
2022-06-29 11:31:34.389696 99.03% [INFO] switch_channel.c:527 RECV DTMF 1:880
2022-06-29 11:31:34.729695 99.03% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 4:1120
2022-06-29 11:31:34.729695 99.03% [INFO] switch_channel.c:527 RECV DTMF 4:1120
2022-06-29 11:31:35.209681 99.03% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF #:1200
2022-06-29 11:31:35.209681 99.03% [INFO] switch_channel.c:527 RECV DTMF #:1200
2022-06-29 11:31:35.209681 99.03% [DEBUG] switch_cpp.cpp:1465 [ASTPP] We recieved a pin : 6314
2022-06-29 11:31:35.209681 99.03% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [validate_card_usage] Query :SELECT DATE_FORMAT('2032-06-21 10:11:08' , '%Y%m%d%H%i%s') AS expiry
2022-06-29 11:31:35.209681 99.03% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [validate_card_usage] Query :SELECT DATE_FORMAT('2022-06-29 08:31:35' , '%Y%m%d%H%i%s') AS expiry
2022-06-29 11:31:35.209681 99.03% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [Accountcode : 127718]
2022-06-29 11:31:35.209681 99.03% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-this-card-has-a-balance-of.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:31:35.209681 99.03% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:31:36.529692 99.03% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-this-card-has-a-balance-of.wav
2022-06-29 11:31:36.529692 99.03% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [Play Amount First Part] Query :5000
2022-06-29 11:31:36.529692 99.03% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [Play Amount Second Part] Query :00
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 say(en number pronounced 5000)
2022-06-29 11:31:36.549627 99.03% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:31:37.749651 99.30% [DEBUG] switch_ivr_play_say.c:2001 done playing file file_string://digits/5.wav!digits/thousand.wav
2022-06-29 11:31:37.769617 99.30% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-point.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:31:37.769617 99.30% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:31:38.329647 99.30% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-point.wav
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 say(en number pronounced 00)
2022-06-29 11:31:38.349661 99.30% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:31:38.969671 99.27% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [770@102.220.200.133] from ip 62.197.148.4
2022-06-29 11:31:39.109696 99.27% [DEBUG] switch_ivr_play_say.c:2001 done playing file file_string://digits/0.wav
2022-06-29 11:31:39.109696 99.27% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-phonenum.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:31:39.109696 99.27% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:31:39.149677 99.27% [WARNING] sofia_reg.c:3223 Can't find user [770@102.220.200.133] from 62.197.148.4
You must define a domain called '102.220.200.133' in your directory and add a user with the id="770" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:31:39.149677 99.27% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [770@102.220.200.133] from ip 62.197.148.4
2022-06-29 11:31:42.829696 99.13% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-phonenum.wav
2022-06-29 11:31:44.449697 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 9:1360
2022-06-29 11:31:44.449697 99.13% [INFO] switch_channel.c:527 RECV DTMF 9:1360
2022-06-29 11:31:44.809704 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 0:880
2022-06-29 11:31:44.809704 99.13% [INFO] switch_channel.c:527 RECV DTMF 0:880
2022-06-29 11:31:45.129699 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:720
2022-06-29 11:31:45.129699 99.13% [INFO] switch_channel.c:527 RECV DTMF 7:720
2022-06-29 11:31:45.409699 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:800
2022-06-29 11:31:45.409699 99.13% [INFO] switch_channel.c:527 RECV DTMF 7:800
2022-06-29 11:31:45.789696 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 9:1440
2022-06-29 11:31:45.789696 99.13% [INFO] switch_channel.c:527 RECV DTMF 9:1440
2022-06-29 11:31:46.149693 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 2:1120
2022-06-29 11:31:46.149693 99.13% [INFO] switch_channel.c:527 RECV DTMF 2:1120
2022-06-29 11:31:46.569695 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 0:960
2022-06-29 11:31:46.569695 99.13% [INFO] switch_channel.c:527 RECV DTMF 0:960
2022-06-29 11:31:46.969699 99.10% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 5:800
2022-06-29 11:31:46.969699 99.10% [INFO] switch_channel.c:527 RECV DTMF 5:800
2022-06-29 11:31:47.329699 99.10% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 0:880
2022-06-29 11:31:47.329699 99.10% [INFO] switch_channel.c:527 RECV DTMF 0:880
2022-06-29 11:31:47.649695 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 9:880
2022-06-29 11:31:47.649695 99.13% [INFO] switch_channel.c:527 RECV DTMF 9:880
2022-06-29 11:31:48.009695 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:880
2022-06-29 11:31:48.009695 99.13% [INFO] switch_channel.c:527 RECV DTMF 7:880
2022-06-29 11:31:48.609693 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF #:1520
2022-06-29 11:31:48.609693 99.13% [INFO] switch_channel.c:527 RECV DTMF #:1520
2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] [CHECK_destination] Dialed destination number :90779205097
2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Account Information ===================
2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] User id : 17
2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] Account code : 127718
2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] Balance : 5000
2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] Type : 0 [0:prepaid,1:postpaid]
2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] Ratecard id : 4
2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] ========================================================
2022-06-29 11:31:48.629672 99.13% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CHECK_BLOCKED_PREFIX] Query :SELECT * FROM block_patterns WHERE (blocked_patterns = '^90779205097.*' OR blocked_patterns = '^9077920509.*' OR blocked_patterns = '^907792050.*' OR blocked_patterns = '^90779205.*' OR blocked_patterns = '^9077920.*' OR blocked_patterns = '^907792.*' OR blocked_patterns = '^90779.*' OR blocked_patterns = '^9077.*' OR blocked_patterns = '^907.*' OR blocked_patterns = '^90.*' OR blocked_patterns = '^9.*' OR blocked_patterns ='--') AND accountid = 17 limit 1 
2022-06-29 11:31:48.629672 99.13% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_PACKAGE_INFO] Query :SELECT *,P.id as package_id,P.product_id as product_id FROM packages_view as P inner join package_patterns as PKGPTR on P.product_id = PKGPTR.product_id WHERE (patterns = '^90779205097.*' OR patterns = '^9077920509.*' OR patterns = '^907792050.*' OR patterns = '^90779205.*' OR patterns = '^9077920.*' OR patterns = '^907792.*' OR patterns = '^90779.*' OR patterns = '^9077.*' OR patterns = '^907.*' OR patterns = '^90.*' OR patterns = '^9.*' OR patterns ='--') AND accountid = 17 ORDER BY LENGTH(PKGPTR.patterns) DESC
2022-06-29 11:31:48.629672 99.13% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 4 AND status = 0
2022-06-29 11:31:48.629672 99.13% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_RATES] call_direction :
2022-06-29 11:31:48.629672 99.13% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_RATES] Query :SELECT * FROM routes WHERE (pattern = '^90779205097.*' OR pattern = '^9077920509.*' OR pattern = '^907792050.*' OR pattern = '^90779205.*' OR pattern = '^9077920.*' OR pattern = '^907792.*' OR pattern = '^90779.*' OR pattern = '^9077.*' OR pattern = '^907.*' OR pattern = '^90.*' OR pattern = '^9.*' OR pattern ='--') AND status = 0 AND (pricelist_id = 4 OR accountid=17)  ORDER BY accountid DESC,LENGTH(pattern) DESC,cost DESC LIMIT 1
2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] call_direction:::::: 
2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Rates Information ===================
2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] ID : 8
2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] Connectcost : 0.00000
2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] Includedseconds : 0
2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] Cost : 220.00000
2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] comment : Uganda
2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] Country Id : 197
2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] Accid : 17
2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] Trunk ID: 3
2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] Routing type: 
2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] ================================================================
2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] [FIND_MAXLENGTH] Your5000 balance Accountid 17 !!!
2022-06-29 11:31:48.629672 99.13% [NOTICE] switch_cpp.cpp:1465 [ASTPP] 22 Minutes
2022-06-29 11:31:48.629672 99.13% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [SAY_TIMELIMIT] MINUTES 22
2022-06-29 11:31:48.629672 99.13% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-this-call-will-last.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:31:48.629672 99.13% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:31:49.809694 99.10% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-this-call-will-last.wav
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 say(en number pronounced 22)
2022-06-29 11:31:49.849656 99.10% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:31:50.929695 99.07% [DEBUG] switch_ivr_play_say.c:2001 done playing file file_string://digits/20.wav!digits/2.wav
2022-06-29 11:31:50.929695 99.07% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-minutes.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:31:50.929695 99.07% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:31:51.549667 99.07% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-minutes.wav
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_CARRIER_RATES] Query :SELECT TK.id as trunk_id,TK.name as trunk_name,TK.codec,GW.name as path,GW.dialplan_variable,TK.provider_id,TR.init_inc,TK.status,TK.maxchannels,TK.cps,TK.leg_timeout,TR.pattern,TR.id as outbound_route_id,TR.connectcost,TR.comment,TR.includedseconds,TR.cost,TR.inc,TR.prepend,TR.strip,(select name from gateways where status=0 AND id = TK.failover_gateway_id) as path1,(select name from gateways where status=0 AND id = TK.failover_gateway_id1) as path2 FROM outbound_routes as TR,trunks as TK,gateways as GW WHERE GW.status=0 AND GW.id= TK.gateway_id AND TK.status=0 AND TK.id= TR.trunk_id AND (pattern = '^90779205097.*' OR pattern = '^9077920509.*' OR pattern = '^907792050.*' OR pattern = '^90779205.*' OR pattern = '^9077920.*' OR pattern = '^907792.*' OR pattern = '^90779.*' OR pattern = '^9077.*' OR pattern = '^907.*' OR pattern = '^90.*' OR pattern = '^9.*' OR pattern ='--') AND TR.status = 0  AND TR.trunk_id IN (3)  ORDER by LENGTH (pattern) DESC,TR.cost ASC,TR.precedence ASC, TK.precedence
2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Termination Rates Information ===================
2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] ID : 6
2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] Code : ^90.*
2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] Destination : Uganda
2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] Connectcost : 0.00000
2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] Free Seconds : 0
2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] Prefix : ^90.*
2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] Strip : 9
2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] Termination rate id : 3
2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] Gateway name : MTN
2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] Failover gateway : 
2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] Vendor id : 18
2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] Max channels : 0
2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] trunk_name : MTN
2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] =================================================================
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(call_processed=internal)
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [call_processed]=[internal]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(callstart=2022-06-29 08:31:51)
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [callstart]=[2022-06-29 08:31:51]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(originated_destination_number=90779205097)
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [originated_destination_number]=[90779205097]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(effective_destination_number=90779205097)
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [effective_destination_number]=[90779205097]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(continue_on_fail=true)
2022-06-29 11:31:51.569670 99.07% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [continue_on_fail]=[true]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(hangup_after_bridge=true)
2022-06-29 11:31:51.569670 99.07% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [hangup_after_bridge]=[true]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(account_id=17)
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [account_id]=[17]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(account_type=0)
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [account_type]=[0]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(resellerid=0)
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [resellerid]=[0]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(parent_id=0)
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [parent_id]=[0]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(accountcode=127718)
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [accountcode]=[127718]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(call_direction=outbound)
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [call_direction]=[outbound]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(calltype=CALLINGCARD)
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [calltype]=[CALLINGCARD]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(origination_rates=ID:8|CODE:^907.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:1|COST:220.00000|INC:60|INITIALBLOCK:60|RATEGROUP:4|MARKUP:0|CI:197|ACCID:17)
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [origination_rates]=[ID:8|CODE:^907.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:1|COST:220.00000|INC:60|INITIALBLOCK:60|RATEGROUP:4|MARKUP:0|CI:197|ACCID:17]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(execute_on_answer=sched_hangup +1320)
2022-06-29 11:31:51.569670 99.07% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [execute_on_answer]=[sched_hangup +1320]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(process_cdr=true)
2022-06-29 11:31:51.569670 99.07% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [process_cdr]=[true]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 sched_hangup(+1320)
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_scheduler.c:263 Added task 6 switch_ivr_schedule_hangup (a5859f66-b4eb-44b9-aaeb-61a5d3692597) to run at 1656492831
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_OVERRIDE_CALLERID] Query :SELECT callerid_name as cid_name,callerid_number as cid_number,accountid FROM accounts_callerid WHERE accountid = 17 AND status=0 LIMIT 1
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(original_caller_id_name=0902)
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [original_caller_id_name]=[0902]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(original_caller_id_number=0902)
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [original_caller_id_number]=[0902]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(presence_data=x|||Dorcas(127718)|||^907.* // Uganda // 220.00000|||MTN // ^90.* // Uganda // 220.00000|||CC)
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [presence_data]=[x|||Dorcas(127718)|||^907.* // Uganda // 220.00000|||MTN // ^90.* // Uganda // 220.00000|||CC]
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,out_caller_id_terminate,number_terminate FROM localization WHERE id=(SELECT localization_id from accounts where id = 18) AND status=0 limit 1 
2022-06-29 11:31:51.569670 99.07% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [DONUMBERTRANSLATION] Before Localization CLI/DST : 90779205097
2022-06-29 11:31:51.569670 99.07% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [DONUMBERTRANSLATION] After Localization CLI/DST : 0779205097
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(termination_rates=ID:6|CODE:^90.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:220.00000|INC:60|TRUNK:3|PROVIDER:18)
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [termination_rates]=[ID:6|CODE:^90.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:220.00000|INC:60|TRUNK:3|PROVIDER:18]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(trunk_id=3)
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [trunk_id]=[3]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(provider_id=18)
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [provider_id]=[18]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(hangup_after_bridge=false)
2022-06-29 11:31:51.569670 99.07% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [hangup_after_bridge]=[false]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(absolute_codec_string=PCMA,G729,PCMA)
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [absolute_codec_string]=[PCMA,G729,PCMA]
EXECUTE [depth=0] sofia/default/0902@102.220.200.133 bridge([leg_timeout=0]sofia/gateway/MTN/0779205097)
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1954 (sofia/default/0902@102.220.200.133) Callstate Change ACTIVE -> RING_WAIT
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [call_processed]=[internal] to event
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [callstart]=[2022-06-29 08:31:51] to event
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [originated_destination_number]=[90779205097] to event
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [effective_destination_number]=[90779205097] to event
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [account_id]=[17] to event
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [account_type]=[0] to event
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [resellerid]=[0] to event
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [parent_id]=[0] to event
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [accountcode]=[127718] to event
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [call_direction]=[outbound] to event
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [calltype]=[CALLINGCARD] to event
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [origination_rates]=[ID:8|CODE:^907.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:1|COST:220.00000|INC:60|INITIALBLOCK:60|RATEGROUP:4|MARKUP:0|CI:197|ACCID:17] to event
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [original_caller_id_name]=[0902] to event
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [original_caller_id_number]=[0902] to event
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [presence_data]=[x|||Dorcas(127718)|||^907.* // Uganda // 220.00000|||MTN // ^90.* // Uganda // 220.00000|||CC] to event
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [termination_rates]=[ID:6|CODE:^90.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:220.00000|INC:60|TRUNK:3|PROVIDER:18] to event
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [trunk_id]=[3] to event
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [provider_id]=[18] to event
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [absolute_codec_string]=[PCMA,G729,PCMA] to event
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_ivr_originate.c:2843 Parsing session specific variables
2022-06-29 11:31:51.569670 99.07% [NOTICE] switch_channel.c:1123 New Channel sofia/default/0779205097 [6cd8f3ac-5e22-479b-b59e-cd0856576536]
2022-06-29 11:31:51.569670 99.07% [DEBUG] mod_sofia.c:5121 (sofia/default/0779205097) State Change CS_NEW -> CS_INIT
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0779205097) Running State Change CS_INIT (Cur 2 Tot 709)
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:624 (sofia/default/0779205097) State INIT
2022-06-29 11:31:51.569670 99.07% [DEBUG] mod_sofia.c:97 sofia/default/0779205097 SOFIA INIT
2022-06-29 11:31:51.569670 99.07% [INFO] sofia_glue.c:1651 sofia/default/0779205097 sending invite call-id: (null)
2022-06-29 11:31:51.569670 99.07% [DEBUG] sofia_glue.c:1654 sofia/default/0779205097 sending invite version: 1.10.7 -release-19-883d2cb662 64bit
Local SDP:
v=0
o=FreeSWITCH 1656466345 1656466346 IN IP4 102.220.200.133
s=FreeSWITCH
c=IN IP4 102.220.200.133
t=0 0
m=audio 25166 RTP/AVP 8 18 101
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv

2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:40 sofia/default/0779205097 Standard INIT
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:48 (sofia/default/0779205097) State Change CS_INIT -> CS_ROUTING
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:624 (sofia/default/0779205097) State INIT going to sleep
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0779205097) Running State Change CS_ROUTING (Cur 2 Tot 709)
2022-06-29 11:31:51.569670 99.07% [DEBUG] sofia.c:7499 Channel sofia/default/0779205097 entering state [calling][0]
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:640 (sofia/default/0779205097) State ROUTING
2022-06-29 11:31:51.569670 99.07% [DEBUG] mod_sofia.c:158 sofia/default/0779205097 SOFIA ROUTING
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_ivr_originate.c:67 (sofia/default/0779205097) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:640 (sofia/default/0779205097) State ROUTING going to sleep
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0779205097) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 709)
2022-06-29 11:31:51.569670 99.07% [DEBUG] sofia.c:7499 Channel sofia/default/0779205097 entering state [terminated][503]
2022-06-29 11:31:51.569670 99.07% [NOTICE] sofia.c:8738 Hangup sofia/default/0779205097 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE]
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:659 (sofia/default/0779205097) State CONSUME_MEDIA
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:659 (sofia/default/0779205097) State CONSUME_MEDIA going to sleep
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0779205097) Running State Change CS_HANGUP (Cur 2 Tot 709)
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:844 (sofia/default/0779205097) Callstate Change DOWN -> HANGUP
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:846 (sofia/default/0779205097) State HANGUP
2022-06-29 11:31:51.569670 99.07% [DEBUG] mod_sofia.c:468 Channel sofia/default/0779205097 hanging up, cause: NORMAL_TEMPORARY_FAILURE
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:59 sofia/default/0779205097 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:846 (sofia/default/0779205097) State HANGUP going to sleep
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:616 (sofia/default/0779205097) State Change CS_HANGUP -> CS_REPORTING
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0779205097) Running State Change CS_REPORTING (Cur 2 Tot 709)
2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:932 (sofia/default/0779205097) State REPORTING
2022-06-29 11:31:51.569670 99.07% [INFO] mod_json_cdr.c:271 Process [6cd8f3ac-5e22-479b-b59e-cd0856576536.cdr.json]
2022-06-29 11:31:51.589613 99.07% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE]
2022-06-29 11:31:51.589613 99.07% [DEBUG] switch_channel.c:2178 (sofia/default/0902@102.220.200.133) Callstate Change RING_WAIT -> ACTIVE
2022-06-29 11:31:51.589613 99.07% [INFO] mod_dptools.c:3653 Originate Failed.  Cause: NORMAL_TEMPORARY_FAILURE
2022-06-29 11:31:51.589613 99.07% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-callingcard-menu.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:31:51.589613 99.07% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:31:51.649679 99.00% [DEBUG] switch_core_state_machine.c:168 sofia/default/0779205097 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
2022-06-29 11:31:51.649679 99.00% [DEBUG] switch_core_state_machine.c:932 (sofia/default/0779205097) State REPORTING going to sleep
2022-06-29 11:31:51.649679 99.00% [DEBUG] switch_core_state_machine.c:607 (sofia/default/0779205097) State Change CS_REPORTING -> CS_DESTROY
2022-06-29 11:31:51.649679 99.00% [DEBUG] switch_core_session.c:1753 Session 709 (sofia/default/0779205097) Locked, Waiting on external entities
2022-06-29 11:31:51.649679 99.00% [NOTICE] switch_core_session.c:1771 Session 709 (sofia/default/0779205097) Ended
2022-06-29 11:31:51.649679 99.00% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/0779205097 [CS_DESTROY]
2022-06-29 11:31:51.649679 99.00% [DEBUG] switch_core_state_machine.c:735 (sofia/default/0779205097) Running State Change CS_DESTROY (Cur 1 Tot 709)
2022-06-29 11:31:51.649679 99.00% [DEBUG] switch_core_state_machine.c:745 (sofia/default/0779205097) State DESTROY
2022-06-29 11:31:51.649679 99.00% [DEBUG] mod_sofia.c:379 sofia/default/0779205097 SOFIA DESTROY
2022-06-29 11:31:51.649679 99.00% [DEBUG] switch_core_state_machine.c:175 sofia/default/0779205097 Standard DESTROY
2022-06-29 11:31:51.649679 99.00% [DEBUG] switch_core_state_machine.c:745 (sofia/default/0779205097) State DESTROY going to sleep
2022-06-29 11:31:57.669694 98.47% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 3:1040
2022-06-29 11:31:57.669694 98.47% [INFO] switch_channel.c:527 RECV DTMF 3:1040
2022-06-29 11:31:57.689639 98.47% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-callingcard-menu.wav
2022-06-29 11:31:57.689639 98.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Got DTMF digits: 3retries:0
2022-06-29 11:31:57.689639 98.47% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-goodbye.wav sample rate 16000 doesn't match requested rate 8000
2022-06-29 11:31:57.689639 98.47% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-goodbye.wav
2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_cpp.cpp:749 CoreSession::hangup
2022-06-29 11:31:58.489662 98.47% [NOTICE] switch_cpp.cpp:751 Hangup sofia/default/0902@102.220.200.133 [CS_EXECUTE] [NORMAL_CLEARING]
2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Got DTMF digits: retries:1
2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Got DTMF digits: retries:2
2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_cpp.cpp:749 CoreSession::hangup
2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_cpp.cpp:1209 sofia/default/0902@102.220.200.133 destroy/unlink session from object
2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_session.c:2983 sofia/default/0902@102.220.200.133 skip receive message [PHONE_EVENT] (channel is hungup already)
2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:647 (sofia/default/0902@102.220.200.133) State EXECUTE going to sleep
2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_HANGUP (Cur 1 Tot 709)
2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:844 (sofia/default/0902@102.220.200.133) Callstate Change ACTIVE -> HANGUP
2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:846 (sofia/default/0902@102.220.200.133) State HANGUP
2022-06-29 11:31:58.489662 98.47% [DEBUG] mod_sofia.c:462 sofia/default/0902@102.220.200.133 Overriding SIP cause 480 with 503 from the other leg
2022-06-29 11:31:58.489662 98.47% [DEBUG] mod_sofia.c:468 Channel sofia/default/0902@102.220.200.133 hanging up, cause: NORMAL_CLEARING
2022-06-29 11:31:58.489662 98.47% [DEBUG] mod_sofia.c:522 Sending BYE to sofia/default/0902@102.220.200.133
2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:59 sofia/default/0902@102.220.200.133 Standard HANGUP, cause: NORMAL_CLEARING
2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:846 (sofia/default/0902@102.220.200.133) State HANGUP going to sleep
2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:616 (sofia/default/0902@102.220.200.133) State Change CS_HANGUP -> CS_REPORTING
2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_REPORTING (Cur 1 Tot 709)
2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:932 (sofia/default/0902@102.220.200.133) State REPORTING
2022-06-29 11:31:58.489662 98.47% [INFO] mod_json_cdr.c:271 Process [a5859f66-b4eb-44b9-aaeb-61a5d3692597.cdr.json]
2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:168 sofia/default/0902@102.220.200.133 Standard REPORTING, cause: NORMAL_CLEARING
2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:932 (sofia/default/0902@102.220.200.133) State REPORTING going to sleep
2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:607 (sofia/default/0902@102.220.200.133) State Change CS_REPORTING -> CS_DESTROY
2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_session.c:1753 Session 708 (sofia/default/0902@102.220.200.133) Locked, Waiting on external entities
2022-06-29 11:31:58.489662 98.47% [NOTICE] switch_core_session.c:1771 Session 708 (sofia/default/0902@102.220.200.133) Ended
2022-06-29 11:31:58.489662 98.47% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/0902@102.220.200.133 [CS_DESTROY]
2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:735 (sofia/default/0902@102.220.200.133) Running State Change CS_DESTROY (Cur 0 Tot 709)
2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:745 (sofia/default/0902@102.220.200.133) State DESTROY
2022-06-29 11:31:58.489662 98.47% [DEBUG] mod_sofia.c:379 sofia/default/0902@102.220.200.133 SOFIA DESTROY
2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:175 sofia/default/0902@102.220.200.133 Standard DESTROY
2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:745 (sofia/default/0902@102.220.200.133) State DESTROY going to sleep
2022-06-29 11:31:58.569698 98.47% [DEBUG] switch_scheduler.c:147 Deleting task 6 switch_ivr_schedule_hangup (a5859f66-b4eb-44b9-aaeb-61a5d3692597)
2022-06-29 11:32:05.209690 97.73% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [670@102.220.200.133] from ip 103.219.21.17
2022-06-29 11:32:37.369662 99.13% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 89.37.173.54
2022-06-29 11:32:42.809696 99.27% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [691@102.220.200.133] from ip 62.197.144.11
2022-06-29 11:32:43.009695 99.27% [WARNING] sofia_reg.c:3223 Can't find user [691@102.220.200.133] from 62.197.144.11
You must define a domain called '102.220.200.133' in your directory and add a user with the id="691" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:32:43.009695 99.27% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [691@102.220.200.133] from ip 62.197.144.11
2022-06-29 11:32:44.649694 99.23% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [3382@102.220.200.133] from ip 85.14.245.202
2022-06-29 11:33:01.589657 99.27% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [763@102.220.200.133] from ip 194.169.170.4
2022-06-29 11:33:11.789691 98.13% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [771@102.220.200.133] from ip 143.244.42.104
2022-06-29 11:33:12.209642 98.13% [WARNING] sofia_reg.c:3223 Can't find user [771@102.220.200.133] from 143.244.42.104
You must define a domain called '102.220.200.133' in your directory and add a user with the id="771" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:33:12.209642 98.13% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [771@102.220.200.133] from ip 143.244.42.104
2022-06-29 11:33:25.369699 98.03% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [770@102.220.200.133] from ip 62.197.156.4
2022-06-29 11:33:26.009635 98.13% [WARNING] sofia_reg.c:3223 Can't find user [770@102.220.200.133] from 62.197.156.4
You must define a domain called '102.220.200.133' in your directory and add a user with the id="770" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:33:26.009635 98.13% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [770@102.220.200.133] from ip 62.197.156.4
2022-06-29 11:33:26.989695 98.23% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [768@102.220.200.133] from ip 45.136.155.56
2022-06-29 11:33:27.409696 98.23% [WARNING] sofia_reg.c:3223 Can't find user [768@102.220.200.133] from 45.136.155.56
You must define a domain called '102.220.200.133' in your directory and add a user with the id="768" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:33:27.409696 98.23% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [768@102.220.200.133] from ip 45.136.155.56
2022-06-29 11:33:47.689698 99.33% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [670@102.220.200.133] from ip 146.70.102.190
2022-06-29 11:33:48.229696 99.33% [WARNING] sofia_reg.c:3223 Can't find user [670@102.220.200.133] from 146.70.102.190
You must define a domain called '102.220.200.133' in your directory and add a user with the id="670" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2022-06-29 11:33:48.229696 99.33% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [670@102.220.200.133] from ip 146.70.102.190
freeswitc