span style="color: goldenrod; font-weight: bold;"> 2021-05-05 08:30:51.657394 [DEBUG] switch_core_state_machine.c:236 sofia/default/2906327411@192.168.1.114:5225 Standard ROUTING 2021-05-05 08:30:51.657394 [INFO] mod_dialplan_xml.c:637 Processing 2906327411 <2906327411>->123456 in context default 2021-05-05 08:30:51.657394 [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes') 2021-05-05 08:30:51.657394 [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons 2021-05-05 08:30:51.677236 [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] Dialed number : 123456 2021-05-05 08:30:51.677236 [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT access_number FROM accessnumber WHERE access_number = '123456' AND status=0 limit 1 2021-05-05 08:30:51.677236 [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="123456"> <condition field="destination_number" expression="123456"> <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/2906327411@192.168.1.114:5225 parsing [default->123456] continue=false Dialplan: sofia/default/2906327411@192.168.1.114:5225 Regex (PASS) [123456] destination_number(123456) =~ /123456/ break=on-false Dialplan: sofia/default/2906327411@192.168.1.114:5225 Action log(INFO ASTPP - Calling Card Call) Dialplan: sofia/default/2906327411@192.168.1.114:5225 Action answer() Dialplan: sofia/default/2906327411@192.168.1.114:5225 Action sleep(2000) Dialplan: sofia/default/2906327411@192.168.1.114:5225 Action lua(astpp-callingcards.lua) 2021-05-05 08:30:51.677236 [DEBUG] switch_core_state_machine.c:287 (sofia/default/2906327411@192.168.1.114:5225) State Change CS_ROUTING -> CS_EXECUTE 2021-05-05 08:30:51.677236 [DEBUG] switch_core_state_machine.c:644 (sofia/default/2906327411@192.168.1.114:5225) State ROUTING going to sleep 2021-05-05 08:30:51.677236 [DEBUG] switch_core_state_machine.c:585 (sofia/default/2906327411@192.168.1.114:5225) Running State Change CS_EXECUTE (Cur 1 Tot 76) 2021-05-05 08:30:51.677236 [DEBUG] switch_core_state_machine.c:651 (sofia/default/2906327411@192.168.1.114:5225) State EXECUTE 2021-05-05 08:30:51.677236 [DEBUG] mod_sofia.c:209 sofia/default/2906327411@192.168.1.114:5225 SOFIA EXECUTE 2021-05-05 08:30:51.677236 [DEBUG] switch_core_state_machine.c:329 sofia/default/2906327411@192.168.1.114:5225 Standard EXECUTE EXECUTE [depth=0] sofia/default/2906327411@192.168.1.114:5225 log(INFO ASTPP - Calling Card Call) 2021-05-05 08:30:51.677236 [INFO] mod_dptools.c:1879 ASTPP - Calling Card Call EXECUTE [depth=0] sofia/default/2906327411@192.168.1.114:5225 answer() 2021-05-05 08:30:51.697231 [DEBUG] switch_core_media.c:8675 AUDIO RTP [sofia/default/2906327411@192.168.1.114:5225] 192.168.1.114 port 27656 -> 117.247.91.162 port 8000 codec: 8 ms: 20 2021-05-05 08:30:51.697231 [DEBUG] switch_rtp.c:4478 Starting timer [soft] 160 bytes per 20ms 2021-05-05 08:30:51.697231 [DEBUG] switch_core_media.c:8989 sofia/default/2906327411@192.168.1.114:5225 Set 2833 dtmf send payload to 101 2021-05-05 08:30:51.697231 [DEBUG] switch_core_media.c:8996 sofia/default/2906327411@192.168.1.114:5225 Set 2833 dtmf receive payload to 101 2021-05-05 08:30:51.697231 [DEBUG] switch_core_media.c:9019 sofia/default/2906327411@192.168.1.114:5225 Set rtp dtmf delay to 40 2021-05-05 08:30:51.697231 [DEBUG] mod_sofia.c:898 Local SDP sofia/default/2906327411@192.168.1.114:5225: v=0 o=FreeSWITCH 1620175795 1620175796 IN IP4 192.168.1.114 s=FreeSWITCH c=IN IP4 192.168.1.114 t=0 0 m=audio 27656 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv 2021-05-05 08:30:51.697231 [NOTICE] mod_dptools.c:1419 Channel [sofia/default/2906327411@192.168.1.114:5225] has been answered 2021-05-05 08:30:51.697231 [DEBUG] switch_channel.c:3865 (sofia/default/2906327411@192.168.1.114:5225) Callstate Change RINGING -> ACTIVE 2021-05-05 08:30:51.697231 [DEBUG] sofia.c:7406 Channel sofia/default/2906327411@192.168.1.114:5225 entering state [completed][200] EXECUTE [depth=0] sofia/default/2906327411@192.168.1.114:5225 sleep(2000) 2021-05-05 08:30:52.037282 [DEBUG] sofia.c:7406 Channel sofia/default/2906327411@192.168.1.114:5225 entering state [ready][200] 2021-05-05 08:30:52.337259 [INFO] switch_rtp.c:7753 Auto Changing audio port from 117.247.91.162:8000 to 10.81.234.12:8000 2021-05-05 08:30:52.637239 [WARNING] sofia_reg.c:1795 SIP auth challenge (REGISTER) on sofia profile 'default' for [2906327411@192.168.1.114] from ip 10.81.234.12 EXECUTE [depth=0] sofia/default/2906327411@192.168.1.114:5225 lua(astpp-callingcards.lua) 2021-05-05 08:30:53.697254 [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes') 2021-05-05 08:30:53.697254 [NOTICE] switch_cpp.cpp:1465 [ASTPP] SECTION 2021-05-05 08:30:53.697254 [DEBUG] switch_core_file.c:405 File /var/www/html/astpp/upload/astpp-welcome.wav sample rate 16000 doesn't match requested rate 8000 2021-05-05 08:30:53.697254 [DEBUG] switch_ivr_play_say.c:1486 Codec Activated L16@8000hz 1 channels 20ms 2021-05-05 08:30:55.497371 [DEBUG] switch_ivr_play_say.c:1931 done playing file /var/www/html/astpp/upload/astpp-welcome.wav 2021-05-05 08:30:55.497371 [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CHECK_DID] Query :SELECT * FROM ani_map WHERE number = 2906327411 2021-05-05 08:30:55.497371 [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT *,(select currencyrate from currency where id=currency_id) as currencyrate FROM accounts WHERE number = "13" AND status=0 AND deleted=0 limit 1 2021-05-05 08:30:55.497371 [ERR] mod_lua.cpp:202 ...switch/scripts/astpp/lib/astpp.callingcard.functions.lua:45: attempt to index local 'cardinfo' (a nil value) stack traceback: ...switch/scripts/astpp/lib/astpp.callingcard.functions.lua:45: in function 'auth_callingcard' /usr/share/freeswitch/scripts/astpp-callingcards.lua:92: in main chunk 2021-05-05 08:30:55.497371 [DEBUG] switch_cpp.cpp:1209 sofia/default/2906327411@192.168.1.114:5225 destroy/unlink session from object 2021-05-05 08:30:55.497371 [NOTICE] switch_core_state_machine.c:386 sofia/default/2906327411@192.168.1.114:5225 has executed the last dialplan instruction, hanging up. 2021-05-05 08:30:55.497371 [NOTICE] switch_core_state_machine.c:388 Hangup sofia/default/2906327411@192.168.1.114:5225 [CS_EXECUTE] [NORMAL_CLEARING] 2021-05-05 08:30:55.497371 [DEBUG] switch_core_state_machine.c:651 (sofia/default/2906327411@192.168.1.114:5225) State EXECUTE going to sleep 2021-05-05 08:30:55.497371 [DEBUG] switch_core_state_machine.c:585 (sofia/default/2906327411@192.168.1.114:5225) Running State Change CS_HANGUP (Cur 1 Tot 76) 2021-05-05 08:30:55.497371 [DEBUG] switch_core_state_machine.c:848 (sofia/default/2906327411@192.168.1.114:5225) Callstate Change ACTIVE -> HANGUP 2021-05-05 08:30:55.497371 [DEBUG] switch_core_state_machine.c:850 (sofia/default/2906327411@192.168.1.114:5225) State HANGUP 2021-05-05 08:30:55.497371 [DEBUG] mod_sofia.c:453 Channel sofia/default/2906327411@192.168.1.114:5225 hanging up, cause: NORMAL_CLEARING 2021-05-05 08:30:55.497371 [DEBUG] mod_sofia.c:507 Sending BYE to sofia/default/2906327411@192.168.1.114:5225 2021-05-05 08:30:55.497371 [DEBUG] switch_core_state_machine.c:60 sofia/default/2906327411@192.168.1.114:5225 Standard HANGUP, cause: NORMAL_CLEARING 2021-05-05 08:30:55.497371 [DEBUG] switch_core_state_machine.c:850 (sofia/default/2906327411@192.168.1.114:5225) State HANGUP going to sleep 2021-05-05 08:30:55.497371 [DEBUG] switch_core_state_machine.c:620 (sofia/default/2906327411@192.168.1.114:5225) State Change CS_HANGUP -> CS_REPORTING 2021-05-05 08:30:55.497371 [DEBUG] switch_core_state_machine.c:585 (sofia/default/2906327411@192.168.1.114:5225) Running State Change CS_REPORTING (Cur 1 Tot 76) 2021-05-05 08:30:55.497371 [DEBUG] switch_core_state_machine.c:936 (sofia/default/2906327411@192.168.1.114:5225) State REPORTING 2021-05-05 08:30:55.497371 [INFO] mod_json_cdr.c:271 Process [4694655d-06e3-480a-bc7c-260e3b0b8ab7.cdr.json] 2021-05-05 08:30:55.497371 [DEBUG] switch_core_state_machine.c:174 sofia/default/2906327411@192.168.1.114:5225 Standard REPORTING, cause: NORMAL_CLEARING 2021-05-05 08:30:55.497371 [DEBUG] switch_core_state_machine.c:936 (sofia/default/2906327411@192.168.1.114:5225) State REPORTING going to sleep 2021-05-05 08:30:55.497371 [DEBUG] switch_core_state_machine.c:611 (sofia/default/2906327411@192.168.1.114:5225) State Change CS_REPORTING -> CS_DESTROY 2021-05-05 08:30:55.497371 [DEBUG] switch_core_session.c:1736 Session 76 (sofia/default/2906327411@192.168.1.114:5225) Locked, Waiting on external entities