freeswitch@ip-172-31-36-75> 2021-12-27 10:17:07.492282 97.50% [NOTICE] switch_channel.c:1123 New Channel sofia/default/5981723017@65.0.92.207:5060 [a79cd207-4f7c-4882-b32a-0585a31cba5c] 2021-12-27 10:17:07.492282 97.50% [DEBUG] switch_core_state_machine.c:581 (sofia/default/5981723017@65.0.92.207:5060) Running State Change CS_NEW (Cur 1 Tot 16) 2021-12-27 10:17:07.492282 97.50% [INFO] sofia.c:10462 sofia/default/5981723017@65.0.92.207:5060 receiving invite from 117.247.91.162:48258 version: 1.10.7 -release-19-883d2cb662 64bit call-id: MGNiZTQwMDVmOTUyZTE0NjYyYzIxNDcxMTJkYTE0YTQ. 2021-12-27 10:17:07.492282 97.50% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 117.247.91.162:0. 2021-12-27 10:17:07.492282 97.50% [DEBUG] sofia.c:2419 detaching session a79cd207-4f7c-4882-b32a-0585a31cba5c 2021-12-27 10:17:07.492282 97.50% [WARNING] sofia_reg.c:1861 SIP auth challenge (INVITE) on sofia profile 'default' for [102345@65.0.92.207] from ip 117.247.91.162 2021-12-27 10:17:07.492282 97.50% [DEBUG] switch_core_state_machine.c:600 (sofia/default/5981723017@65.0.92.207:5060) State NEW 2021-12-27 10:17:07.572298 97.50% [DEBUG] sofia.c:2532 Re-attaching to session a79cd207-4f7c-4882-b32a-0585a31cba5c 2021-12-27 10:17:07.592271 97.50% [INFO] sofia.c:10462 sofia/default/5981723017@65.0.92.207:5060 receiving invite from 117.247.91.162:48258 version: 1.10.7 -release-19-883d2cb662 64bit call-id: MGNiZTQwMDVmOTUyZTE0NjYyYzIxNDcxMTJkYTE0YTQ. 2021-12-27 10:17:07.592271 97.50% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 117.247.91.162:0. 2021-12-27 10:17:07.592271 97.50% [DEBUG] sofia.c:11672 Setting NAT mode based on via received 2021-12-27 10:17:07.592271 97.50% [DEBUG] sofia.c:7499 Channel sofia/default/5981723017@65.0.92.207:5060 entering state [received][100] 2021-12-27 10:17:07.592271 97.50% [DEBUG] sofia.c:7509 Remote SDP: v=0 o=Z 0 0 IN IP4 117.247.91.162 s=Z c=IN IP4 117.247.91.162 t=0 0 m=audio 2728 RTP/AVP 3 110 8 0 98 101 a=rtpmap:110 speex/8000 a=rtpmap:98 iLBC/8000 a=fmtp:98 mode=20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 2021-12-27 10:17:07.592271 97.50% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1] 2021-12-27 10:17:07.592271 97.50% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1] 2021-12-27 10:17:07.592271 97.50% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [speex:110:8000:20:0:1]/[PCMA:8:8000:20:64000:1] 2021-12-27 10:17:07.592271 97.50% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [speex:110:8000:20:0:1]/[PCMU:0:8000:20:64000:1] 2021-12-27 10:17:07.592271 97.50% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2021-12-27 10:17:07.592271 97.50% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 2021-12-27 10:17:07.592271 97.50% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2021-12-27 10:17:07.592271 97.50% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2021-12-27 10:17:07.592271 97.50% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2021-12-27 10:17:07.592271 97.50% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 2021-12-27 10:17:07.592271 97.50% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [iLBC:98:8000:30:0:1]/[PCMA:8:8000:20:64000:1] 2021-12-27 10:17:07.592271 97.50% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [iLBC:98:8000:30:0:1]/[PCMU:0:8000:20:64000:1] 2021-12-27 10:17:07.592271 97.50% [DEBUG] switch_core_media.c:5566 Set telephone-event payload to 101@8000 2021-12-27 10:17:07.592271 97.50% [DEBUG] switch_core_media.c:3870 Set Codec sofia/default/5981723017@65.0.92.207:5060 PCMA/8000 20 ms 160 samples 64000 bits 1 channels 2021-12-27 10:17:07.592271 97.50% [DEBUG] switch_core_codec.c:111 sofia/default/5981723017@65.0.92.207:5060 Original read codec set to PCMA:8 2021-12-27 10:17:07.592271 97.50% [DEBUG] switch_core_media.c:5915 Set telephone-event payload to 101@8000 2021-12-27 10:17:07.592271 97.50% [DEBUG] switch_core_media.c:5973 sofia/default/5981723017@65.0.92.207:5060 Set 2833 dtmf send payload to 101 recv payload to 101 2021-12-27 10:17:07.592271 97.50% [DEBUG] sofia.c:7933 (sofia/default/5981723017@65.0.92.207:5060) State Change CS_NEW -> CS_INIT 2021-12-27 10:17:07.592271 97.50% [DEBUG] switch_core_state_machine.c:581 (sofia/default/5981723017@65.0.92.207:5060) Running State Change CS_INIT (Cur 1 Tot 16) 2021-12-27 10:17:07.592271 97.50% [DEBUG] switch_core_state_machine.c:624 (sofia/default/5981723017@65.0.92.207:5060) State INIT 2021-12-27 10:17:07.592271 97.50% [DEBUG] mod_sofia.c:97 sofia/default/5981723017@65.0.92.207:5060 SOFIA INIT 2021-12-27 10:17:07.592271 97.50% [DEBUG] switch_core_state_machine.c:40 sofia/default/5981723017@65.0.92.207:5060 Standard INIT 2021-12-27 10:17:07.592271 97.50% [DEBUG] switch_core_state_machine.c:48 (sofia/default/5981723017@65.0.92.207:5060) State Change CS_INIT -> CS_ROUTING 2021-12-27 10:17:07.592271 97.50% [DEBUG] switch_core_state_machine.c:624 (sofia/default/5981723017@65.0.92.207:5060) State INIT going to sleep 2021-12-27 10:17:07.592271 97.50% [DEBUG] switch_core_state_machine.c:581 (sofia/default/5981723017@65.0.92.207:5060) Running State Change CS_ROUTING (Cur 1 Tot 16) 2021-12-27 10:17:07.592271 97.50% [DEBUG] switch_channel.c:2380 (sofia/default/5981723017@65.0.92.207:5060) Callstate Change DOWN -> RINGING 2021-12-27 10:17:07.592271 97.50% [DEBUG] switch_core_state_machine.c:640 (sofia/default/5981723017@65.0.92.207:5060) State ROUTING 2021-12-27 10:17:07.592271 97.50% [DEBUG] mod_sofia.c:158 sofia/default/5981723017@65.0.92.207:5060 SOFIA ROUTING 2021-12-27 10:17:07.592271 97.50% [DEBUG] switch_core_state_machine.c:230 sofia/default/5981723017@65.0.92.207:5060 Standard ROUTING 2021-12-27 10:17:07.592271 97.50% [INFO] mod_dialplan_xml.c:639 Processing 5981723017 <5981723017>->102345 in context default 2021-12-27 10:17:07.592271 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes') 2021-12-27 10:17:07.612270 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons 2021-12-27 10:17:07.612270 97.50% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] Dialed number : 102345 2021-12-27 10:17:07.612270 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT access_number FROM accessnumber WHERE access_number = '102345' AND status=0 limit 1 2021-12-27 10:17:07.612270 97.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Generated XML:
Dialplan: sofia/default/5981723017@65.0.92.207:5060 parsing [default->102345] continue=false Dialplan: sofia/default/5981723017@65.0.92.207:5060 Regex (PASS) [102345] destination_number(102345) =~ /102345/ break=on-false Dialplan: sofia/default/5981723017@65.0.92.207:5060 Action log(INFO ASTPP - Calling Card Call) Dialplan: sofia/default/5981723017@65.0.92.207:5060 Action answer() Dialplan: sofia/default/5981723017@65.0.92.207:5060 Action sleep(2000) Dialplan: sofia/default/5981723017@65.0.92.207:5060 Action lua(astpp-callingcards.lua) 2021-12-27 10:17:07.612270 97.50% [DEBUG] switch_core_state_machine.c:281 (sofia/default/5981723017@65.0.92.207:5060) State Change CS_ROUTING -> CS_EXECUTE 2021-12-27 10:17:07.612270 97.50% [DEBUG] switch_core_state_machine.c:640 (sofia/default/5981723017@65.0.92.207:5060) State ROUTING going to sleep 2021-12-27 10:17:07.612270 97.50% [DEBUG] switch_core_state_machine.c:581 (sofia/default/5981723017@65.0.92.207:5060) Running State Change CS_EXECUTE (Cur 1 Tot 16) 2021-12-27 10:17:07.612270 97.50% [DEBUG] switch_core_state_machine.c:647 (sofia/default/5981723017@65.0.92.207:5060) State EXECUTE 2021-12-27 10:17:07.612270 97.50% [DEBUG] mod_sofia.c:213 sofia/default/5981723017@65.0.92.207:5060 SOFIA EXECUTE 2021-12-27 10:17:07.612270 97.50% [DEBUG] switch_core_state_machine.c:323 sofia/default/5981723017@65.0.92.207:5060 Standard EXECUTE EXECUTE [depth=0] sofia/default/5981723017@65.0.92.207:5060 log(INFO ASTPP - Calling Card Call) 2021-12-27 10:17:07.612270 97.50% [INFO] mod_dptools.c:1879 ASTPP - Calling Card Call EXECUTE [depth=0] sofia/default/5981723017@65.0.92.207:5060 answer() 2021-12-27 10:17:07.612270 97.50% [DEBUG] switch_core_media.c:8777 AUDIO RTP [sofia/default/5981723017@65.0.92.207:5060] 172.31.36.75 port 29514 -> 117.247.91.162 port 2728 codec: 8 ms: 20 2021-12-27 10:17:07.612270 97.50% [DEBUG] switch_rtp.c:4619 Starting timer [soft] 160 bytes per 20ms 2021-12-27 10:17:07.612270 97.50% [DEBUG] switch_core_media.c:9089 sofia/default/5981723017@65.0.92.207:5060 Set 2833 dtmf send payload to 101 2021-12-27 10:17:07.612270 97.50% [DEBUG] switch_core_media.c:9096 sofia/default/5981723017@65.0.92.207:5060 Set 2833 dtmf receive payload to 101 2021-12-27 10:17:07.612270 97.50% [DEBUG] switch_core_media.c:9119 sofia/default/5981723017@65.0.92.207:5060 Set rtp dtmf delay to 40 2021-12-27 10:17:07.612270 97.50% [DEBUG] mod_sofia.c:913 Local SDP sofia/default/5981723017@65.0.92.207:5060: v=0 o=FreeSWITCH 1640570713 1640570714 IN IP4 65.0.92.207 s=FreeSWITCH c=IN IP4 65.0.92.207 t=0 0 m=audio 29514 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv 2021-12-27 10:17:07.612270 97.50% [DEBUG] sofia.c:7499 Channel sofia/default/5981723017@65.0.92.207:5060 entering state [completed][200] 2021-12-27 10:17:07.612270 97.50% [NOTICE] mod_dptools.c:1419 Channel [sofia/default/5981723017@65.0.92.207:5060] has been answered 2021-12-27 10:17:07.612270 97.50% [DEBUG] switch_channel.c:3950 (sofia/default/5981723017@65.0.92.207:5060) Callstate Change RINGING -> ACTIVE EXECUTE [depth=0] sofia/default/5981723017@65.0.92.207:5060 sleep(2000) 2021-12-27 10:17:07.652269 97.50% [DEBUG] sofia.c:7499 Channel sofia/default/5981723017@65.0.92.207:5060 entering state [ready][200] 2021-12-27 10:17:07.692298 97.50% [DEBUG] switch_rtp.c:7934 Correct audio ip/port confirmed. EXECUTE [depth=0] sofia/default/5981723017@65.0.92.207:5060 lua(astpp-callingcards.lua) 2021-12-27 10:17:09.612292 97.37% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes') 2021-12-27 10:17:09.612292 97.37% [NOTICE] switch_cpp.cpp:1465 [ASTPP] SECTION 2021-12-27 10:17:09.612292 97.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 2021-12-27 10:17:09.612292 97.37% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 20ms 2021-12-27 10:17:11.412300 97.30% [DEBUG] switch_ivr_play_say.c:2001 done playing file /var/www/html/astpp/upload/astpp-welcome.wav 2021-12-27 10:17:11.412300 97.30% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [get_ani] Query :SELECT * FROM ani_map WHERE number = 5981723017 2021-12-27 10:17:11.412300 97.30% [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 2021-12-27 10:17:11.412300 97.30% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 20ms 2021-12-27 10:17:14.412291 97.27% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-accountnum.wav 2021-12-27 10:17:15.152289 97.30% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 5:960 2021-12-27 10:17:15.152289 97.30% [INFO] switch_channel.c:527 RECV DTMF 5:960 2021-12-27 10:17:15.652282 97.30% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 9:960 2021-12-27 10:17:15.652282 97.30% [INFO] switch_channel.c:527 RECV DTMF 9:960 2021-12-27 10:17:17.412284 97.30% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 8:960 2021-12-27 10:17:17.412284 97.30% [INFO] switch_channel.c:527 RECV DTMF 8:960 2021-12-27 10:17:17.972293 97.30% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:960 2021-12-27 10:17:17.972293 97.30% [INFO] switch_channel.c:527 RECV DTMF 1:960 2021-12-27 10:17:18.632302 97.30% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:960 2021-12-27 10:17:18.632302 97.30% [INFO] switch_channel.c:527 RECV DTMF 7:960 2021-12-27 10:17:20.512272 97.27% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 2:960 2021-12-27 10:17:20.512272 97.27% [INFO] switch_channel.c:527 RECV DTMF 2:960 2021-12-27 10:17:21.212276 97.27% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 3:960 2021-12-27 10:17:21.212276 97.27% [INFO] switch_channel.c:527 RECV DTMF 3:960 2021-12-27 10:17:22.092298 97.23% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 0:960 2021-12-27 10:17:22.092298 97.23% [INFO] switch_channel.c:527 RECV DTMF 0:960 2021-12-27 10:17:22.832301 97.23% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:960 2021-12-27 10:17:22.832301 97.23% [INFO] switch_channel.c:527 RECV DTMF 1:960 2021-12-27 10:17:23.252305 97.23% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:960 2021-12-27 10:17:23.252305 97.23% [INFO] switch_channel.c:527 RECV DTMF 7:960 2021-12-27 10:17:24.052310 97.23% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF #:960 2021-12-27 10:17:24.052310 97.23% [INFO] switch_channel.c:527 RECV DTMF #:960 2021-12-27 10:17:24.052310 97.23% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Got DTMF digits: 5981723017 2021-12-27 10:17:24.052310 97.23% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT *,(select currencyrate from currency where id=currency_id) as currencyrate FROM accounts WHERE number = "5981723017" AND status=0 AND deleted=0 limit 1 2021-12-27 10:17:24.052310 97.23% [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 2021-12-27 10:17:24.052310 97.23% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 20ms 2021-12-27 10:17:26.772299 97.23% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-pleasepin.wav 2021-12-27 10:17:28.652289 97.23% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 9:960 2021-12-27 10:17:28.652289 97.23% [INFO] switch_channel.c:527 RECV DTMF 9:960 2021-12-27 10:17:30.492298 97.27% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 5:960 2021-12-27 10:17:30.492298 97.27% [INFO] switch_channel.c:527 RECV DTMF 5:960 2021-12-27 10:17:32.852302 98.70% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 4:960 2021-12-27 10:17:32.852302 98.70% [INFO] switch_channel.c:527 RECV DTMF 4:960 2021-12-27 10:17:33.632294 99.40% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 8:960 2021-12-27 10:17:33.632294 99.40% [INFO] switch_channel.c:527 RECV DTMF 8:960 2021-12-27 10:17:34.492303 99.40% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 6:960 2021-12-27 10:17:34.492303 99.40% [INFO] switch_channel.c:527 RECV DTMF 6:960 2021-12-27 10:17:34.932284 99.47% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:960 2021-12-27 10:17:34.932284 99.47% [INFO] switch_channel.c:527 RECV DTMF 1:960 2021-12-27 10:17:36.912302 99.50% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF #:960 2021-12-27 10:17:36.912302 99.50% [INFO] switch_channel.c:527 RECV DTMF #:960 2021-12-27 10:17:36.912302 99.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] We Recieved A Pin Number : 954861 2021-12-27 10:17:36.912302 99.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [validate_card_usage] Query :SELECT DATE_FORMAT('2031-12-25 08:10:31' , '%Y%m%d%H%i%s') AS expiry 2021-12-27 10:17:36.912302 99.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [validate_card_usage] Query :SELECT DATE_FORMAT('2021-12-27 10:17:36' , '%Y%m%d%H%i%s') AS expiry 2021-12-27 10:17:36.912302 99.50% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-register.wav sample rate 16000 doesn't match requested rate 8000 2021-12-27 10:17:36.912302 99.50% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 20ms 2021-12-27 10:17:39.732272 99.63% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-register.wav 2021-12-27 10:17:44.732292 99.70% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [Accountcode : 5981723017] 2021-12-27 10:17:44.732292 99.70% [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 2021-12-27 10:17:44.732292 99.70% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 20ms 2021-12-27 10:17:46.052337 99.70% [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 2021-12-27 10:17:46.052337 99.70% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [Play Amount First Part] Query :393 2021-12-27 10:17:46.052337 99.70% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [Play Amount Second Part] Query :1 EXECUTE [depth=0] sofia/default/5981723017@65.0.92.207:5060 say(en number pronounced 393) 2021-12-27 10:17:46.052337 99.70% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 20ms 2021-12-27 10:17:48.052294 99.67% [DEBUG] switch_ivr_play_say.c:2001 done playing file file_string://digits/3.wav!digits/hundred.wav!digits/90.wav!digits/3.wav 2021-12-27 10:17:48.052294 99.67% [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 2021-12-27 10:17:48.052294 99.67% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 20ms 2021-12-27 10:17:48.612275 99.67% [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/5981723017@65.0.92.207:5060 say(en number pronounced 1) 2021-12-27 10:17:48.612275 99.67% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 20ms 2021-12-27 10:17:49.312305 99.63% [DEBUG] switch_ivr_play_say.c:2001 done playing file file_string://digits/1.wav 2021-12-27 10:17:49.312305 99.63% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [HP:access_number_call_flow[0:Go Direct Dial,1:Go IVR] : 0] 2021-12-27 10:17:49.312305 99.63% [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 2021-12-27 10:17:49.312305 99.63% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 20ms 2021-12-27 10:17:53.012289 99.63% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-phonenum.wav 2021-12-27 10:17:54.252283 99.63% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:960 2021-12-27 10:17:54.252283 99.63% [INFO] switch_channel.c:527 RECV DTMF 1:960 2021-12-27 10:17:54.652316 99.63% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 0:960 2021-12-27 10:17:54.652316 99.63% [INFO] switch_channel.c:527 RECV DTMF 0:960 2021-12-27 10:17:54.852290 99.63% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 2:960 2021-12-27 10:17:54.852290 99.63% [INFO] switch_channel.c:527 RECV DTMF 2:960 2021-12-27 10:17:55.032282 99.63% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 2:960 2021-12-27 10:17:55.032282 99.63% [INFO] switch_channel.c:527 RECV DTMF 2:960 2021-12-27 10:17:55.192297 99.63% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 2:960 2021-12-27 10:17:55.192297 99.63% [INFO] switch_channel.c:527 RECV DTMF 2:960 2021-12-27 10:17:55.572279 99.63% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 3:960 2021-12-27 10:17:55.572279 99.63% [INFO] switch_channel.c:527 RECV DTMF 3:960 2021-12-27 10:17:55.732306 99.63% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 3:960 2021-12-27 10:17:55.732306 99.63% [INFO] switch_channel.c:527 RECV DTMF 3:960 2021-12-27 10:17:55.912297 99.63% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 3:960 2021-12-27 10:17:55.912297 99.63% [INFO] switch_channel.c:527 RECV DTMF 3:960 2021-12-27 10:17:56.952292 99.63% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF #:960 2021-12-27 10:17:56.952292 99.63% [INFO] switch_channel.c:527 RECV DTMF #:960 2021-12-27 10:17:56.952292 99.63% [INFO] switch_cpp.cpp:1465 [ASTPP] [CHECK Destination] Dialed Destination Number :10222333 2021-12-27 10:17:56.952292 99.63% [ERR] mod_lua.cpp:202 /usr/share/freeswitch/scripts/astpp/lib/astpp.functions.lua:389: attempt to concatenate local 'accountid' (a nil value) stack traceback: /usr/share/freeswitch/scripts/astpp/lib/astpp.functions.lua:389: in function 'check_call_barring' ...switch/scripts/astpp/lib/astpp.callingcard.functions.lua:925: in function 'process_destination' /usr/share/freeswitch/scripts/astpp-callingcards.lua:106: in main chunk 2021-12-27 10:17:56.952292 99.63% [DEBUG] switch_cpp.cpp:1209 sofia/default/5981723017@65.0.92.207:5060 destroy/unlink session from object 2021-12-27 10:17:56.952292 99.63% [NOTICE] switch_core_state_machine.c:382 sofia/default/5981723017@65.0.92.207:5060 has executed the last dialplan instruction, hanging up. 2021-12-27 10:17:56.952292 99.63% [NOTICE] switch_core_state_machine.c:384 Hangup sofia/default/5981723017@65.0.92.207:5060 [CS_EXECUTE] [NORMAL_CLEARING] 2021-12-27 10:17:56.952292 99.63% [DEBUG] switch_core_state_machine.c:647 (sofia/default/5981723017@65.0.92.207:5060) State EXECUTE going to sleep 2021-12-27 10:17:56.952292 99.63% [DEBUG] switch_core_state_machine.c:581 (sofia/default/5981723017@65.0.92.207:5060) Running State Change CS_HANGUP (Cur 1 Tot 16) 2021-12-27 10:17:56.952292 99.63% [DEBUG] switch_core_state_machine.c:844 (sofia/default/5981723017@65.0.92.207:5060) Callstate Change ACTIVE -> HANGUP 2021-12-27 10:17:56.952292 99.63% [DEBUG] switch_core_state_machine.c:846 (sofia/default/5981723017@65.0.92.207:5060) State HANGUP 2021-12-27 10:17:56.952292 99.63% [DEBUG] mod_sofia.c:468 Channel sofia/default/5981723017@65.0.92.207:5060 hanging up, cause: NORMAL_CLEARING 2021-12-27 10:17:56.952292 99.63% [DEBUG] mod_sofia.c:522 Sending BYE to sofia/default/5981723017@65.0.92.207:5060 2021-12-27 10:17:56.952292 99.63% [DEBUG] switch_core_state_machine.c:59 sofia/default/5981723017@65.0.92.207:5060 Standard HANGUP, cause: NORMAL_CLEARING 2021-12-27 10:17:56.952292 99.63% [DEBUG] switch_core_state_machine.c:846 (sofia/default/5981723017@65.0.92.207:5060) State HANGUP going to sleep 2021-12-27 10:17:56.952292 99.63% [DEBUG] switch_core_state_machine.c:616 (sofia/default/5981723017@65.0.92.207:5060) State Change CS_HANGUP -> CS_REPORTING 2021-12-27 10:17:56.952292 99.63% [DEBUG] switch_core_state_machine.c:581 (sofia/default/5981723017@65.0.92.207:5060) Running State Change CS_REPORTING (Cur 1 Tot 16) 2021-12-27 10:17:56.952292 99.63% [DEBUG] switch_core_state_machine.c:932 (sofia/default/5981723017@65.0.92.207:5060) State REPORTING 2021-12-27 10:17:56.952292 99.63% [INFO] mod_json_cdr.c:271 Process [a79cd207-4f7c-4882-b32a-0585a31cba5c.cdr.json] 2021-12-27 10:17:56.952292 99.63% [DEBUG] switch_core_state_machine.c:168 sofia/default/5981723017@65.0.92.207:5060 Standard REPORTING, cause: NORMAL_CLEARING 2021-12-27 10:17:56.952292 99.63% [DEBUG] switch_core_state_machine.c:932 (sofia/default/5981723017@65.0.92.207:5060) State REPORTING going to sleep 2021-12-27 10:17:56.952292 99.63% [DEBUG] switch_core_state_machine.c:607 (sofia/default/5981723017@65.0.92.207:5060) State Change CS_REPORTING -> CS_DESTROY 2021-12-27 10:17:56.952292 99.63% [DEBUG] switch_core_session.c:1753 Session 16 (sofia/default/5981723017@65.0.92.207:5060) Locked, Waiting on external entities 2021-12-27 10:17:56.952292 99.63% [NOTICE] switch_core_session.c:1771 Session 16 (sofia/default/5981723017@65.0.92.207:5060) Ended 2021-12-27 10:17:56.952292 99.63% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/5981723017@65.0.92.207:5060 [CS_DESTROY] 2021-12-27 10:17:56.952292 99.63% [DEBUG] switch_core_state_machine.c:735 (sofia/default/5981723017@65.0.92.207:5060) Running State Change CS_DESTROY (Cur 0 Tot 16) 2021-12-27 10:17:56.952292 99.63% [DEBUG] switch_core_state_machine.c:745 (sofia/default/5981723017@65.0.92.207:5060) State DESTROY 2021-12-27 10:17:56.952292 99.63% [DEBUG] mod_sofia.c:379 sofia/default/5981723017@65.0.92.207:5060 SOFIA DESTROY 2021-12-27 10:17:56.952292 99.63% [DEBUG] switch_core_state_machine.c:175 sofia/default/5981723017@65.0.92.207:5060 Standard DESTROY 2021-12-27 10:17:56.952292 99.63% [DEBUG] switch_core_state_machine.c:745 (sofia/default/5981723017@65.0.92.207:5060) State DESTROY going to sleep freeswitch@ip-172-31-36-75>