From Prashant Kumar, 2 Years ago, written in FreeSWITCH.
- view diff
Embed
  1. span style="color: cornflowerblue; font-weight: bold;"> 2021-12-27 10:35:45.772299 98.97% [NOTICE] switch_channel.c:1123 New Channel sofia/default/5981723017@65.0.92.207:5060 [e606b16f-f4a1-4ae9-8853-c95dfeacccce]
  2. 2021-12-27 10:35:45.772299 98.97% [DEBUG] switch_core_state_machine.c:581 (sofia/default/5981723017@65.0.92.207:5060) Running State Change CS_NEW (Cur 1 Tot 23)
  3. 2021-12-27 10:35:45.772299 98.97% [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: ZjEyYjZmN2M2ZWQxODU2ODg4MGQ2OWIzOThhMDdhZjU.
  4. 2021-12-27 10:35:45.772299 98.97% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 117.247.91.162:0.
  5. 2021-12-27 10:35:45.772299 98.97% [DEBUG] sofia.c:2419 detaching session e606b16f-f4a1-4ae9-8853-c95dfeacccce
  6. 2021-12-27 10:35:45.772299 98.97% [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
  7. 2021-12-27 10:35:45.772299 98.97% [DEBUG] switch_core_state_machine.c:600 (sofia/default/5981723017@65.0.92.207:5060) State NEW
  8. 2021-12-27 10:35:46.252282 98.93% [DEBUG] sofia.c:2532 Re-attaching to session e606b16f-f4a1-4ae9-8853-c95dfeacccce
  9. 2021-12-27 10:35:46.272270 98.93% [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: ZjEyYjZmN2M2ZWQxODU2ODg4MGQ2OWIzOThhMDdhZjU.
  10. 2021-12-27 10:35:46.272270 98.93% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 117.247.91.162:0.
  11. 2021-12-27 10:35:46.272270 98.93% [DEBUG] sofia.c:11672 Setting NAT mode based on via received
  12. 2021-12-27 10:35:46.272270 98.93% [DEBUG] sofia.c:7499 Channel sofia/default/5981723017@65.0.92.207:5060 entering state [received][100]
  13. 2021-12-27 10:35:46.272270 98.93% [DEBUG] sofia.c:7509 Remote SDP:
  14. v=0
  15. o=Z 0 0 IN IP4 117.247.91.162
  16. s=Z
  17. c=IN IP4 117.247.91.162
  18. t=0 0
  19. m=audio 2731 RTP/AVP 3 110 8 0 98 101
  20. a=rtpmap:110 speex/8000
  21. a=rtpmap:98 iLBC/8000
  22. a=fmtp:98 mode=20
  23. a=rtpmap:101 telephone-event/8000
  24. a=fmtp:101 0-15
  25.  
  26. 2021-12-27 10:35:46.272270 98.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
  27. 2021-12-27 10:35:46.272270 98.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
  28. 2021-12-27 10:35:46.272270 98.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [speex:110:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
  29. 2021-12-27 10:35:46.272270 98.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [speex:110:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
  30. 2021-12-27 10:35:46.272270 98.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  31. 2021-12-27 10:35:46.272270 98.93% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  32. 2021-12-27 10:35:46.272270 98.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  33. 2021-12-27 10:35:46.272270 98.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  34. 2021-12-27 10:35:46.272270 98.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  35. 2021-12-27 10:35:46.272270 98.93% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  36. 2021-12-27 10:35:46.272270 98.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [iLBC:98:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
  37. 2021-12-27 10:35:46.272270 98.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [iLBC:98:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
  38. 2021-12-27 10:35:46.272270 98.93% [DEBUG] switch_core_media.c:5566 Set telephone-event payload to 101@8000
  39. 2021-12-27 10:35:46.272270 98.93% [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
  40. 2021-12-27 10:35:46.272270 98.93% [DEBUG] switch_core_codec.c:111 sofia/default/5981723017@65.0.92.207:5060 Original read codec set to PCMA:8
  41. 2021-12-27 10:35:46.272270 98.93% [DEBUG] switch_core_media.c:5915 Set telephone-event payload to 101@8000
  42. 2021-12-27 10:35:46.272270 98.93% [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
  43. 2021-12-27 10:35:46.272270 98.93% [DEBUG] sofia.c:7933 (sofia/default/5981723017@65.0.92.207:5060) State Change CS_NEW -> CS_INIT
  44. 2021-12-27 10:35:46.272270 98.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/5981723017@65.0.92.207:5060) Running State Change CS_INIT (Cur 1 Tot 23)
  45. 2021-12-27 10:35:46.272270 98.93% [DEBUG] switch_core_state_machine.c:624 (sofia/default/5981723017@65.0.92.207:5060) State INIT
  46. 2021-12-27 10:35:46.272270 98.93% [DEBUG] mod_sofia.c:97 sofia/default/5981723017@65.0.92.207:5060 SOFIA INIT
  47. 2021-12-27 10:35:46.272270 98.93% [DEBUG] switch_core_state_machine.c:40 sofia/default/5981723017@65.0.92.207:5060 Standard INIT
  48. 2021-12-27 10:35:46.272270 98.93% [DEBUG] switch_core_state_machine.c:48 (sofia/default/5981723017@65.0.92.207:5060) State Change CS_INIT -> CS_ROUTING
  49. 2021-12-27 10:35:46.272270 98.93% [DEBUG] switch_core_state_machine.c:624 (sofia/default/5981723017@65.0.92.207:5060) State INIT going to sleep
  50. 2021-12-27 10:35:46.272270 98.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/5981723017@65.0.92.207:5060) Running State Change CS_ROUTING (Cur 1 Tot 23)
  51. 2021-12-27 10:35:46.272270 98.93% [DEBUG] switch_channel.c:2380 (sofia/default/5981723017@65.0.92.207:5060) Callstate Change DOWN -> RINGING
  52. 2021-12-27 10:35:46.272270 98.93% [DEBUG] switch_core_state_machine.c:640 (sofia/default/5981723017@65.0.92.207:5060) State ROUTING
  53. 2021-12-27 10:35:46.272270 98.93% [DEBUG] mod_sofia.c:158 sofia/default/5981723017@65.0.92.207:5060 SOFIA ROUTING
  54. 2021-12-27 10:35:46.272270 98.93% [DEBUG] switch_core_state_machine.c:230 sofia/default/5981723017@65.0.92.207:5060 Standard ROUTING
  55. 2021-12-27 10:35:46.272270 98.93% [INFO] mod_dialplan_xml.c:639 Processing 5981723017 <5981723017>->102345 in context default
  56. 2021-12-27 10:35:46.292272 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')
  57. 2021-12-27 10:35:46.292272 98.93% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
  58. 2021-12-27 10:35:46.292272 98.93% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] Dialed number : 102345
  59. 2021-12-27 10:35:46.292272 98.93% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT access_number FROM accessnumber WHERE access_number = '102345' AND status=0 limit 1
  60. 2021-12-27 10:35:46.292272 98.93% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Generated XML:
  61. <?xml version="1.0" encoding="UTF-8" standalone="no"?>
  62. <document type="freeswitch/xml">
  63. <section name="dialplan" description="ASTPP Dialplan">
  64. <context name="default">
  65. <extension name="102345">
  66. <condition field="destination_number" expression="102345">
  67. <action application="log" data="INFO ASTPP - Calling Card Call"/>
  68. <action application="answer"/>
  69. <action application="sleep" data="2000"/>
  70. <action application="lua" data="astpp-callingcards.lua"/>
  71. </condition>
  72. </extension>
  73. </context>
  74. </section>
  75. </document>
  76. Dialplan: sofia/default/5981723017@65.0.92.207:5060 parsing [default->102345] continue=false
  77. Dialplan: sofia/default/5981723017@65.0.92.207:5060 Regex (PASS) [102345] destination_number(102345) =~ /102345/ break=on-false
  78. Dialplan: sofia/default/5981723017@65.0.92.207:5060 Action log(INFO ASTPP - Calling Card Call)
  79. Dialplan: sofia/default/5981723017@65.0.92.207:5060 Action answer()
  80. Dialplan: sofia/default/5981723017@65.0.92.207:5060 Action sleep(2000)
  81. Dialplan: sofia/default/5981723017@65.0.92.207:5060 Action lua(astpp-callingcards.lua)
  82. 2021-12-27 10:35:46.292272 98.93% [DEBUG] switch_core_state_machine.c:281 (sofia/default/5981723017@65.0.92.207:5060) State Change CS_ROUTING -> CS_EXECUTE
  83. 2021-12-27 10:35:46.292272 98.93% [DEBUG] switch_core_state_machine.c:640 (sofia/default/5981723017@65.0.92.207:5060) State ROUTING going to sleep
  84. 2021-12-27 10:35:46.292272 98.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/5981723017@65.0.92.207:5060) Running State Change CS_EXECUTE (Cur 1 Tot 23)
  85. 2021-12-27 10:35:46.292272 98.93% [DEBUG] switch_core_state_machine.c:647 (sofia/default/5981723017@65.0.92.207:5060) State EXECUTE
  86. 2021-12-27 10:35:46.292272 98.93% [DEBUG] mod_sofia.c:213 sofia/default/5981723017@65.0.92.207:5060 SOFIA EXECUTE
  87. 2021-12-27 10:35:46.292272 98.93% [DEBUG] switch_core_state_machine.c:323 sofia/default/5981723017@65.0.92.207:5060 Standard EXECUTE
  88. EXECUTE [depth=0] sofia/default/5981723017@65.0.92.207:5060 log(INFO ASTPP - Calling Card Call)
  89. 2021-12-27 10:35:46.292272 98.93% [INFO] mod_dptools.c:1879 ASTPP - Calling Card Call
  90. EXECUTE [depth=0] sofia/default/5981723017@65.0.92.207:5060 answer()
  91. 2021-12-27 10:35:46.292272 98.93% [DEBUG] switch_core_media.c:8777 AUDIO RTP [sofia/default/5981723017@65.0.92.207:5060] 172.31.36.75 port 26808 -> 117.247.91.162 port 2731 codec: 8 ms: 20
  92. 2021-12-27 10:35:46.292272 98.93% [DEBUG] switch_rtp.c:4619 Starting timer [soft] 160 bytes per 20ms
  93. 2021-12-27 10:35:46.292272 98.93% [DEBUG] switch_core_media.c:9089 sofia/default/5981723017@65.0.92.207:5060 Set 2833 dtmf send payload to 101
  94. 2021-12-27 10:35:46.292272 98.93% [DEBUG] switch_core_media.c:9096 sofia/default/5981723017@65.0.92.207:5060 Set 2833 dtmf receive payload to 101
  95. 2021-12-27 10:35:46.292272 98.93% [DEBUG] switch_core_media.c:9119 sofia/default/5981723017@65.0.92.207:5060 Set rtp dtmf delay to 40
  96. 2021-12-27 10:35:46.292272 98.93% [DEBUG] mod_sofia.c:913 Local SDP sofia/default/5981723017@65.0.92.207:5060:
  97. v=0
  98. o=FreeSWITCH 1640574538 1640574539 IN IP4 65.0.92.207
  99. s=FreeSWITCH
  100. c=IN IP4 65.0.92.207
  101. t=0 0
  102. m=audio 26808 RTP/AVP 8 101
  103. a=rtpmap:8 PCMA/8000
  104. a=rtpmap:101 telephone-event/8000
  105. a=fmtp:101 0-15
  106. a=ptime:20
  107. a=sendrecv
  108.  
  109. 2021-12-27 10:35:46.292272 98.93% [DEBUG] sofia.c:7499 Channel sofia/default/5981723017@65.0.92.207:5060 entering state [completed][200]
  110. 2021-12-27 10:35:46.292272 98.93% [NOTICE] mod_dptools.c:1419 Channel [sofia/default/5981723017@65.0.92.207:5060] has been answered
  111. 2021-12-27 10:35:46.292272 98.93% [DEBUG] switch_channel.c:3950 (sofia/default/5981723017@65.0.92.207:5060) Callstate Change RINGING -> ACTIVE
  112. EXECUTE [depth=0] sofia/default/5981723017@65.0.92.207:5060 sleep(2000)
  113. 2021-12-27 10:35:46.332270 98.93% [DEBUG] sofia.c:7499 Channel sofia/default/5981723017@65.0.92.207:5060 entering state [ready][200]
  114. 2021-12-27 10:35:46.352272 98.93% [DEBUG] switch_rtp.c:7934 Correct audio ip/port confirmed.
  115. EXECUTE [depth=0] sofia/default/5981723017@65.0.92.207:5060 lua(astpp-callingcards.lua)
  116. 2021-12-27 10:35:48.292292 98.63% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes')
  117. 2021-12-27 10:35:48.312276 98.63% [NOTICE] switch_cpp.cpp:1465 [ASTPP] SECTION
  118. 2021-12-27 10:35:48.312276 98.63% [DEBUG] switch_core_file.c:444 File /var/www/html/astpp/upload/astpp-welcome.wav sample rate 16000 doesn't match requested rate 8000
  119. 2021-12-27 10:35:48.312276 98.63% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 20ms
  120. 2021-12-27 10:35:50.092295 98.63% [DEBUG] switch_ivr_play_say.c:2001 done playing file /var/www/html/astpp/upload/astpp-welcome.wav
  121. 2021-12-27 10:35:50.092295 98.63% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [get_ani] Query :SELECT * FROM ani_map WHERE number = 5981723017
  122. 2021-12-27 10:35:50.092295 98.63% [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
  123. 2021-12-27 10:35:50.092295 98.63% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 20ms
  124. 2021-12-27 10:35:53.092306 98.83% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-accountnum.wav
  125. 2021-12-27 10:35:58.312310 99.30% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 5:960
  126. 2021-12-27 10:35:58.312310 99.30% [INFO] switch_channel.c:527 RECV DTMF 5:960
  127. 2021-12-27 10:35:58.772282 99.30% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 9:960
  128. 2021-12-27 10:35:58.772282 99.30% [INFO] switch_channel.c:527 RECV DTMF 9:960
  129. 2021-12-27 10:36:00.652283 99.30% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 8:960
  130. 2021-12-27 10:36:00.652283 99.30% [INFO] switch_channel.c:527 RECV DTMF 8:960
  131. 2021-12-27 10:36:01.292304 99.27% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:960
  132. 2021-12-27 10:36:01.292304 99.27% [INFO] switch_channel.c:527 RECV DTMF 1:960
  133. 2021-12-27 10:36:01.692276 99.27% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:960
  134. 2021-12-27 10:36:01.692276 99.27% [INFO] switch_channel.c:527 RECV DTMF 7:960
  135. 2021-12-27 10:36:02.112272 99.23% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 2:960
  136. 2021-12-27 10:36:02.112272 99.23% [INFO] switch_channel.c:527 RECV DTMF 2:960
  137. 2021-12-27 10:36:02.392275 99.23% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 3:960
  138. 2021-12-27 10:36:02.392275 99.23% [INFO] switch_channel.c:527 RECV DTMF 3:960
  139. 2021-12-27 10:36:02.912284 97.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 0:960
  140. 2021-12-27 10:36:02.912284 97.07% [INFO] switch_channel.c:527 RECV DTMF 0:960
  141. 2021-12-27 10:36:04.192300 96.93% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:960
  142. 2021-12-27 10:36:04.192300 96.93% [INFO] switch_channel.c:527 RECV DTMF 1:960
  143. 2021-12-27 10:36:04.672284 96.93% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:960
  144. 2021-12-27 10:36:04.672284 96.93% [INFO] switch_channel.c:527 RECV DTMF 7:960
  145. 2021-12-27 10:36:05.852270 96.90% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF #:960
  146. span style="color: green; font-weight: bold;"> 2021-12-27 10:36:05.852270 96.90% [INFO] switch_channel.c:527 RECV DTMF #:960
  147. span style="color: goldenrod; font-weight: bold;"> 2021-12-27 10:36:05.852270 96.90% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Got DTMF digits: 5981723017
  148. 2021-12-27 10:36:05.852270 96.90% [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
  149. 2021-12-27 10:36:05.872267 96.90% [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
  150. 2021-12-27 10:36:05.872267 96.90% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 20ms
  151. 2021-12-27 10:36:08.572281 96.87% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-pleasepin.wav
  152. 2021-12-27 10:36:09.372300 96.90% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 9:960
  153. 2021-12-27 10:36:09.372300 96.90% [INFO] switch_channel.c:527 RECV DTMF 9:960
  154. 2021-12-27 10:36:10.572295 96.87% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 5:960
  155. 2021-12-27 10:36:10.572295 96.87% [INFO] switch_channel.c:527 RECV DTMF 5:960
  156. 2021-12-27 10:36:11.832292 96.87% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 4:960
  157. 2021-12-27 10:36:11.832292 96.87% [INFO] switch_channel.c:527 RECV DTMF 4:960
  158. 2021-12-27 10:36:12.892274 96.83% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 8:960
  159. 2021-12-27 10:36:12.892274 96.83% [INFO] switch_channel.c:527 RECV DTMF 8:960
  160. 2021-12-27 10:36:13.352294 96.83% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 6:960
  161. 2021-12-27 10:36:13.352294 96.83% [INFO] switch_channel.c:527 RECV DTMF 6:960
  162. 2021-12-27 10:36:13.772301 96.83% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:960
  163. 2021-12-27 10:36:13.772301 96.83% [INFO] switch_channel.c:527 RECV DTMF 1:960
  164. 2021-12-27 10:36:15.312307 96.80% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF #:960
  165. span style="color: green; font-weight: bold;"> 2021-12-27 10:36:15.312307 96.80% [INFO] switch_channel.c:527 RECV DTMF #:960
  166. span style="color: goldenrod; font-weight: bold;"> 2021-12-27 10:36:15.312307 96.80% [DEBUG] switch_cpp.cpp:1465 [ASTPP] We Recieved A Pin Number : 954861
  167. 2021-12-27 10:36:15.312307 96.80% [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
  168. 2021-12-27 10:36:15.312307 96.80% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [validate_card_usage] Query :SELECT DATE_FORMAT('2021-12-27 10:36:15' , '%Y%m%d%H%i%s') AS expiry
  169. 2021-12-27 10:36:15.312307 96.80% [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
  170. 2021-12-27 10:36:15.312307 96.80% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 20ms
  171. 2021-12-27 10:36:18.132292 97.10% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-register.wav
  172. 2021-12-27 10:36:23.132301 97.13% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [Accountcode : 5981723017]
  173. 2021-12-27 10:36:23.132301 97.13% [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
  174. 2021-12-27 10:36:23.132301 97.13% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 20ms
  175. 2021-12-27 10:36:24.452302 97.10% [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
  176. 2021-12-27 10:36:24.452302 97.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [Play Amount First Part] Query :403
  177. 2021-12-27 10:36:24.452302 97.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [Play Amount Second Part] Query :1
  178. EXECUTE [depth=0] sofia/default/5981723017@65.0.92.207:5060 say(en number pronounced 403)
  179. 2021-12-27 10:36:24.472266 97.10% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 20ms
  180. 2021-12-27 10:36:26.032304 97.17% [DEBUG] switch_ivr_play_say.c:2001 done playing file file_string://digits/4.wav!digits/hundred.wav!digits/3.wav
  181. 2021-12-27 10:36:26.032304 97.17% [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
  182. 2021-12-27 10:36:26.032304 97.17% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 20ms
  183. 2021-12-27 10:36:26.592301 97.17% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-point.wav
  184. EXECUTE [depth=0] sofia/default/5981723017@65.0.92.207:5060 say(en number pronounced 1)
  185. 2021-12-27 10:36:26.612265 97.17% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 20ms
  186. 2021-12-27 10:36:27.292295 97.10% [DEBUG] switch_ivr_play_say.c:2001 done playing file file_string://digits/1.wav
  187. 2021-12-27 10:36:27.292295 97.10% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [HP:access_number_call_flow[0:Go Direct Dial,1:Go IVR] : 1]
  188. 2021-12-27 10:36:27.292295 97.10% [INFO] switch_cpp.cpp:1465 [ASTPP] Press 1 for make call, Press 2 for Recharge using Coupon
  189. 2021-12-27 10:36:27.292295 97.10% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-dailnumber-or-refill.wav sample rate 22050 doesn't match requested rate 8000
  190. 2021-12-27 10:36:27.292295 97.10% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 20ms
  191. 2021-12-27 10:36:31.952287 97.10% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-dailnumber-or-refill.wav
  192. 2021-12-27 10:36:33.692295 99.27% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:960
  193. 2021-12-27 10:36:33.692295 99.27% [INFO] switch_channel.c:527 RECV DTMF 1:960
  194. 2021-12-27 10:36:33.692295 99.27% [INFO] switch_cpp.cpp:1465 [ASTPP] ivr_custom_dtmf:: 1
  195. 2021-12-27 10:36:33.692295 99.27% [INFO] switch_cpp.cpp:1465 [ASTPP] DTMF:1 Redirect in direct dial:
  196. 2021-12-27 10:36:33.692295 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
  197. 2021-12-27 10:36:33.692295 99.27% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 20ms
  198. 2021-12-27 10:36:37.392282 99.47% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-phonenum.wav
  199. 2021-12-27 10:36:38.572272 99.47% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:960
  200. 2021-12-27 10:36:38.572272 99.47% [INFO] switch_channel.c:527 RECV DTMF 1:960
  201. 2021-12-27 10:36:38.952272 99.43% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 0:960
  202. 2021-12-27 10:36:38.952272 99.43% [INFO] switch_channel.c:527 RECV DTMF 0:960
  203. 2021-12-27 10:36:39.332285 99.43% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 2:960
  204. 2021-12-27 10:36:39.332285 99.43% [INFO] switch_channel.c:527 RECV DTMF 2:960
  205. 2021-12-27 10:36:39.512282 99.43% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 2:960
  206. 2021-12-27 10:36:39.512282 99.43% [INFO] switch_channel.c:527 RECV DTMF 2:960
  207. 2021-12-27 10:36:39.672296 99.43% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 3:960
  208. 2021-12-27 10:36:39.672296 99.43% [INFO] switch_channel.c:527 RECV DTMF 3:960
  209. 2021-12-27 10:36:39.832297 99.43% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 9:960
  210. 2021-12-27 10:36:39.832297 99.43% [INFO] switch_channel.c:527 RECV DTMF 9:960
  211. 2021-12-27 10:36:40.012287 99.37% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 3:960
  212. 2021-12-27 10:36:40.012287 99.37% [INFO] switch_channel.c:527 RECV DTMF 3:960
  213. 2021-12-27 10:36:41.552302 99.37% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF #:960
  214. span style="color: green; font-weight: bold;"> 2021-12-27 10:36:41.552302 99.37% [INFO] switch_channel.c:527 RECV DTMF #:960
  215. span style="color: green; font-weight: bold;"> 2021-12-27 10:36:41.552302 99.37% [INFO] switch_cpp.cpp:1465 [ASTPP] [CHECK Destination] Dialed Destination Number :1022393
  216. 2021-12-27 10:36:41.552302 99.37% [ERR] mod_lua.cpp:202 /usr/share/freeswitch/scripts/astpp/lib/astpp.functions.lua:389: attempt to concatenate local 'accountid' (a nil value)
  217. stack traceback:
  218.         /usr/share/freeswitch/scripts/astpp/lib/astpp.functions.lua:389: in function 'check_call_barring'
  219.         ...switch/scripts/astpp/lib/astpp.callingcard.functions.lua:925: in function 'process_destination'
  220.         ...switch/scripts/astpp/lib/astpp.callingcard.functions.lua:611: in function 'process_ivr_custom'
  221.         /usr/share/freeswitch/scripts/astpp-callingcards.lua:108: in main chunk
  222. 2021-12-27 10:36:41.552302 99.37% [DEBUG] switch_cpp.cpp:1209 sofia/default/5981723017@65.0.92.207:5060 destroy/unlink session from object
  223. 2021-12-27 10:36:41.552302 99.37% [NOTICE] switch_core_state_machine.c:382 sofia/default/5981723017@65.0.92.207:5060 has executed the last dialplan instruction, hanging up.
  224. 2021-12-27 10:36:41.552302 99.37% [NOTICE] switch_core_state_machine.c:384 Hangup sofia/default/5981723017@65.0.92.207:5060 [CS_EXECUTE] [NORMAL_CLEARING]
  225. 2021-12-27 10:36:41.552302 99.37% [DEBUG] switch_core_state_machine.c:647 (sofia/default/5981723017@65.0.92.207:5060) State EXECUTE going to sleep
  226. 2021-12-27 10:36:41.552302 99.37% [DEBUG] switch_core_state_machine.c:581 (sofia/default/5981723017@65.0.92.207:5060) Running State Change CS_HANGUP (Cur 1 Tot 23)
  227. 2021-12-27 10:36:41.552302 99.37% [DEBUG] switch_core_state_machine.c:844 (sofia/default/5981723017@65.0.92.207:5060) Callstate Change ACTIVE -> HANGUP
  228. 2021-12-27 10:36:41.552302 99.37% [DEBUG] switch_core_state_machine.c:846 (sofia/default/5981723017@65.0.92.207:5060) State HANGUP
  229. 2021-12-27 10:36:41.552302 99.37% [DEBUG] mod_sofia.c:468 Channel sofia/default/5981723017@65.0.92.207:5060 hanging up, cause: NORMAL_CLEARING
  230. 2021-12-27 10:36:41.552302 99.37% [DEBUG] mod_sofia.c:522 Sending BYE to sofia/default/5981723017@65.0.92.207:5060
  231. 2021-12-27 10:36:41.552302 99.37% [DEBUG] switch_core_state_machine.c:59 sofia/default/5981723017@65.0.92.207:5060 Standard HANGUP, cause: NORMAL_CLEARING
  232. 2021-12-27 10:36:41.552302 99.37% [DEBUG] switch_core_state_machine.c:846 (sofia/default/5981723017@65.0.92.207:5060) State HANGUP going to sleep
  233. 2021-12-27 10:36:41.552302 99.37% [DEBUG] switch_core_state_machine.c:616 (sofia/default/5981723017@65.0.92.207:5060) State Change CS_HANGUP -> CS_REPORTING
  234. 2021-12-27 10:36:41.552302 99.37% [DEBUG] switch_core_state_machine.c:581 (sofia/default/5981723017@65.0.92.207:5060) Running State Change CS_REPORTING (Cur 1 Tot 23)
  235. 2021-12-27 10:36:41.552302 99.37% [DEBUG] switch_core_state_machine.c:932 (sofia/default/5981723017@65.0.92.207:5060) State REPORTING
  236. 2021-12-27 10:36:41.552302 99.37% [INFO] mod_json_cdr.c:271 Process [e606b16f-f4a1-4ae9-8853-c95dfeacccce.cdr.json]
  237. 2021-12-27 10:36:41.572345 99.37% [DEBUG] switch_core_state_machine.c:168 sofia/default/5981723017@65.0.92.207:5060 Standard REPORTING, cause: NORMAL_CLEARING
  238. 2021-12-27 10:36:41.572345 99.37% [DEBUG] switch_core_state_machine.c:932 (sofia/default/5981723017@65.0.92.207:5060) State REPORTING going to sleep
  239. 2021-12-27 10:36:41.572345 99.37% [DEBUG] switch_core_state_machine.c:607 (sofia/default/5981723017@65.0.92.207:5060) State Change CS_REPORTING -> CS_DESTROY
  240. 2021-12-27 10:36:41.572345 99.37% [DEBUG] switch_core_session.c:1753 Session 23 (sofia/default/5981723017@65.0.92.207:5060) Locked, Waiting on external entities
  241. 2021-12-27 10:36:41.572345 99.37% [NOTICE] switch_core_session.c:1771 Session 23 (sofia/default/5981723017@65.0.92.207:5060) Ended
  242. 2021-12-27 10:36:41.572345 99.37% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/5981723017@65.0.92.207:5060 [CS_DESTROY]
  243. 2021-12-27 10:36:41.572345 99.37% [DEBUG] switch_core_state_machine.c:735 (sofia/default/5981723017@65.0.92.207:5060) Running State Change CS_DESTROY (Cur 0 Tot 23)
  244. 2021-12-27 10:36:41.572345 99.37% [DEBUG] switch_core_state_machine.c:745 (sofia/default/5981723017@65.0.92.207:5060) State DESTROY
  245. 2021-12-27 10:36:41.572345 99.37% [DEBUG] mod_sofia.c:379 sofia/default/5981723017@65.0.92.207:5060 SOFIA DESTROY
  246. 2021-12-27 10:36:41.572345 99.37% [DEBUG] switch_core_state_machine.c:175 sofia/default/5981723017@65.0.92.207:5060 Standard DESTROY
  247. 2021-12-27 10:36:41.572345 99.37% [DEBUG] switch_core_state_machine.c:745 (sofia/default/5981723017@65.0.92.207:5060) State DESTROY going to sleep
  248. freeswitch@ip-172-31-36-75>
  249.