From Prashant Kumar, 3 Months ago, written in FreeSWITCH.
- view diff
Embed
  1. span style="color: cornflowerblue; font-weight: bold;"> 2024-01-21 18:12:20.970716 95.70% [NOTICE] switch_channel.c:1142 New Channel sofia/default/4727985745@pk1betav602.astppbilling.org:5078 [0a41f4c0-85cd-4d42-9918-f85d60f90de5]
  2. 2024-01-21 18:12:20.970716 95.70% [DEBUG] switch_core_state_machine.c:581 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) Running State Change CS_NEW (Cur 1 Tot 16)
  3. 2024-01-21 18:12:20.970716 95.70% [INFO] sofia.c:10459 sofia/default/4727985745@pk1betav602.astppbilling.org:5078 receiving invite from 106.206.200.54:56643 version: 1.10.10-release  64bit call-id: OWZhYTdmZDRiNzM2YjEzNjczMDFmZGUxYTJjYzZkZGQ.
  4. 2024-01-21 18:12:20.970716 95.70% [DEBUG] sofia.c:10553 verifying acl "default" for ip/port 106.206.200.54:0.
  5. 2024-01-21 18:12:20.970716 95.70% [DEBUG] sofia.c:2419 detaching session 0a41f4c0-85cd-4d42-9918-f85d60f90de5
  6. 2024-01-21 18:12:20.970716 95.70% [WARNING] sofia_reg.c:1842 SIP auth challenge (INVITE) on sofia profile 'default' for [90770@pk1betav602.astppbilling.org] from ip 106.206.200.54
  7. 2024-01-21 18:12:20.970716 95.70% [DEBUG] switch_core_state_machine.c:600 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) State NEW
  8. 2024-01-21 18:12:21.510739 95.73% [DEBUG] sofia.c:2532 Re-attaching to session 0a41f4c0-85cd-4d42-9918-f85d60f90de5
  9. 2024-01-21 18:12:21.510739 95.73% [INFO] sofia.c:10459 sofia/default/4727985745@pk1betav602.astppbilling.org:5078 receiving invite from 106.206.200.54:56643 version: 1.10.10-release  64bit call-id: OWZhYTdmZDRiNzM2YjEzNjczMDFmZGUxYTJjYzZkZGQ.
  10. 2024-01-21 18:12:21.510739 95.73% [DEBUG] sofia.c:10553 verifying acl "default" for ip/port 106.206.200.54:0.
  11. 2024-01-21 18:12:21.510739 95.73% [DEBUG] sofia.c:11674 Setting NAT mode based on via received
  12. 2024-01-21 18:12:21.510739 95.73% [DEBUG] sofia.c:7493 Channel sofia/default/4727985745@pk1betav602.astppbilling.org:5078 entering state [received][100]
  13. 2024-01-21 18:12:21.510739 95.73% [DEBUG] sofia.c:7503 Remote SDP:
  14. v=0
  15. o=Z 0 0 IN IP4 106.206.200.54
  16. s=Z
  17. c=IN IP4 106.206.200.54
  18. t=0 0
  19. m=audio 8000 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. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
  27. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
  28. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [speex:110:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
  29. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [speex:110:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
  30. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  31. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_media.c:5588 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  32. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  33. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  34. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  35. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_media.c:5588 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  36. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [iLBC:98:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
  37. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [iLBC:98:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
  38. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_media.c:5438 Set telephone-event payload to 101@8000
  39. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_media.c:3734 Set Codec sofia/default/4727985745@pk1betav602.astppbilling.org:5078 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
  40. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_codec.c:111 sofia/default/4727985745@pk1betav602.astppbilling.org:5078 Original read codec set to PCMA:8
  41. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_media.c:5798 Set telephone-event payload to 101@8000
  42. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_media.c:5856 sofia/default/4727985745@pk1betav602.astppbilling.org:5078 Set 2833 dtmf send payload to 101 recv payload to 101
  43. 2024-01-21 18:12:21.510739 95.73% [DEBUG] sofia.c:7927 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) State Change CS_NEW -> CS_INIT
  44. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_state_machine.c:581 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) Running State Change CS_INIT (Cur 1 Tot 16)
  45. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_state_machine.c:624 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) State INIT
  46. 2024-01-21 18:12:21.510739 95.73% [DEBUG] mod_sofia.c:97 sofia/default/4727985745@pk1betav602.astppbilling.org:5078 SOFIA INIT
  47. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_state_machine.c:40 sofia/default/4727985745@pk1betav602.astppbilling.org:5078 Standard INIT
  48. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_state_machine.c:48 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) State Change CS_INIT -> CS_ROUTING
  49. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_state_machine.c:624 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) State INIT going to sleep
  50. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_state_machine.c:581 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) Running State Change CS_ROUTING (Cur 1 Tot 16)
  51. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_channel.c:2399 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) Callstate Change DOWN -> RINGING
  52. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_state_machine.c:640 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) State ROUTING
  53. 2024-01-21 18:12:21.510739 95.73% [DEBUG] mod_sofia.c:158 sofia/default/4727985745@pk1betav602.astppbilling.org:5078 SOFIA ROUTING
  54. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_state_machine.c:230 sofia/default/4727985745@pk1betav602.astppbilling.org:5078 Standard ROUTING
  55. 2024-01-21 18:12:21.510739 95.73% [INFO] mod_dialplan_xml.c:639 Processing 4727985745 <4727985745>->90770 in context default
  56. 2024-01-21 18:12:21.510739 95.73% [INFO] switch_cpp.cpp:1465 [ASTPP] USING CACHE
  57. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_SYSTEM]1.0
  58. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_SYSTEM]1.0
  59. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
  60. 2024-01-21 18:12:21.510739 95.73% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] Dialed number : 90770
  61. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_ACCESS_NUMBER]1.0
  62. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_ACCESS_NUMBER]1.1
  63. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_ACCESS_NUMBER]1.2 :: CALL IS ACCESS NUMBER
  64. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Generated XML:
  65. <?xml version="1.0" encoding="UTF-8" standalone="no"?>
  66. <document type="freeswitch/xml">
  67. <section name="dialplan" description="ASTPP Dialplan">
  68. <context name="default">
  69. <extension name="90770">
  70. <condition field="destination_number" expression="90770">
  71. <action application="log" data="INFO ASTPP - Calling Card Call"/>
  72. <action application="answer"/>
  73. <action application="sleep" data="2000"/>
  74. <action application="set" data="variable_sip_to_port=5078"/>
  75. <action application="set" data="variable_sip_to_host=pk1betav602.astppbilling.org"/>
  76. <action application="lua" data="astpp-callingcards.lua"/>
  77. </condition>
  78. </extension>
  79. </context>
  80. </section>
  81. </document>
  82. Dialplan: sofia/default/4727985745@pk1betav602.astppbilling.org:5078 parsing [default->90770] continue=false
  83. Dialplan: sofia/default/4727985745@pk1betav602.astppbilling.org:5078 Regex (PASS) [90770] destination_number(90770) =~ /90770/ break=on-false
  84. Dialplan: sofia/default/4727985745@pk1betav602.astppbilling.org:5078 Action log(INFO ASTPP - Calling Card Call)
  85. Dialplan: sofia/default/4727985745@pk1betav602.astppbilling.org:5078 Action answer()
  86. Dialplan: sofia/default/4727985745@pk1betav602.astppbilling.org:5078 Action sleep(2000)
  87. Dialplan: sofia/default/4727985745@pk1betav602.astppbilling.org:5078 Action set(variable_sip_to_port=5078)
  88. Dialplan: sofia/default/4727985745@pk1betav602.astppbilling.org:5078 Action set(variable_sip_to_host=pk1betav602.astppbilling.org)
  89. Dialplan: sofia/default/4727985745@pk1betav602.astppbilling.org:5078 Action lua(astpp-callingcards.lua)
  90. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_state_machine.c:281 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) State Change CS_ROUTING -> CS_EXECUTE
  91. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_state_machine.c:640 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) State ROUTING going to sleep
  92. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_state_machine.c:581 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) Running State Change CS_EXECUTE (Cur 1 Tot 16)
  93. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_state_machine.c:647 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) State EXECUTE
  94. 2024-01-21 18:12:21.510739 95.73% [DEBUG] mod_sofia.c:213 sofia/default/4727985745@pk1betav602.astppbilling.org:5078 SOFIA EXECUTE
  95. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_state_machine.c:323 sofia/default/4727985745@pk1betav602.astppbilling.org:5078 Standard EXECUTE
  96. EXECUTE [depth=0] sofia/default/4727985745@pk1betav602.astppbilling.org:5078 log(INFO ASTPP - Calling Card Call)
  97. 2024-01-21 18:12:21.510739 95.73% [INFO] mod_dptools.c:1865 ASTPP - Calling Card Call
  98. EXECUTE [depth=0] sofia/default/4727985745@pk1betav602.astppbilling.org:5078 answer()
  99. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_media.c:8659 AUDIO RTP [sofia/default/4727985745@pk1betav602.astppbilling.org:5078] 172.31.0.164 port 20908 -> 106.206.200.54 port 8000 codec: 8 ms: 20
  100. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_rtp.c:4373 Starting timer [soft] 160 bytes per 20ms
  101. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_media.c:8972 sofia/default/4727985745@pk1betav602.astppbilling.org:5078 Set 2833 dtmf send payload to 101
  102. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_media.c:8979 sofia/default/4727985745@pk1betav602.astppbilling.org:5078 Set 2833 dtmf receive payload to 101
  103. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_core_media.c:9002 sofia/default/4727985745@pk1betav602.astppbilling.org:5078 Set rtp dtmf delay to 40
  104. 2024-01-21 18:12:21.510739 95.73% [DEBUG] mod_sofia.c:914 Local SDP sofia/default/4727985745@pk1betav602.astppbilling.org:5078:
  105. v=0
  106. o=FreeSWITCH 1705839833 1705839834 IN IP4 15.206.212.57
  107. s=FreeSWITCH
  108. c=IN IP4 15.206.212.57
  109. t=0 0
  110. m=audio 20908 RTP/AVP 8 101
  111. a=rtpmap:8 PCMA/8000
  112. a=rtpmap:101 telephone-event/8000
  113. a=fmtp:101 0-15
  114. a=ptime:20
  115. a=sendrecv
  116.  
  117. 2024-01-21 18:12:21.510739 95.73% [DEBUG] sofia.c:7493 Channel sofia/default/4727985745@pk1betav602.astppbilling.org:5078 entering state [completed][200]
  118. 2024-01-21 18:12:21.510739 95.73% [NOTICE] mod_dptools.c:1406 Channel [sofia/default/4727985745@pk1betav602.astppbilling.org:5078] has been answered
  119. 2024-01-21 18:12:21.510739 95.73% [DEBUG] switch_channel.c:3912 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) Callstate Change RINGING -> ACTIVE
  120. EXECUTE [depth=0] sofia/default/4727985745@pk1betav602.astppbilling.org:5078 sleep(2000)
  121. 2024-01-21 18:12:21.950715 95.73% [DEBUG] switch_rtp.c:7503 Correct audio ip/port confirmed.
  122. 2024-01-21 18:12:21.950715 95.73% [DEBUG] sofia.c:7493 Channel sofia/default/4727985745@pk1betav602.astppbilling.org:5078 entering state [ready][200]
  123. EXECUTE [depth=0] sofia/default/4727985745@pk1betav602.astppbilling.org:5078 set(variable_sip_to_port=5078)
  124. 2024-01-21 18:12:23.550729 94.83% [DEBUG] mod_dptools.c:1671 SET sofia/default/4727985745@pk1betav602.astppbilling.org:5078 [variable_sip_to_port]=[5078]
  125. EXECUTE [depth=0] sofia/default/4727985745@pk1betav602.astppbilling.org:5078 set(variable_sip_to_host=pk1betav602.astppbilling.org)
  126. 2024-01-21 18:12:23.550729 94.83% [DEBUG] mod_dptools.c:1671 SET sofia/default/4727985745@pk1betav602.astppbilling.org:5078 [variable_sip_to_host]=[pk1betav602.astppbilling.org]
  127. EXECUTE [depth=0] sofia/default/4727985745@pk1betav602.astppbilling.org:5078 lua(astpp-callingcards.lua)
  128. 2024-01-21 18:12:23.550729 94.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_SYSTEM]1.0
  129. 2024-01-21 18:12:23.550729 94.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','international_prefixes','interconnect_code')
  130. 2024-01-21 18:12:23.550729 94.83% [NOTICE] switch_cpp.cpp:1465 [ASTPP] SECTION
  131. 2024-01-21 18:12:23.550729 94.83% [DEBUG] switch_core_file.c:444 File /var/www/html/astpp/upload/astpp-welcome.wav sample rate 16000 doesn't match requested rate 8000
  132. 2024-01-21 18:12:23.550729 94.83% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
  133. 2024-01-21 18:12:25.350731 94.83% [DEBUG] switch_ivr_play_say.c:2010 done playing file /var/www/html/astpp/upload/astpp-welcome.wav
  134. 2024-01-21 18:12:25.350731 94.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [get_ani] Query :SELECT * FROM ani_map WHERE number = 4727985745
  135. 2024-01-21 18:12:25.350731 94.83% [DEBUG] switch_core_file.c:444 File /usr/local/freeswitch/sounds/en/us/callie/astpp-accountnum.wav sample rate 16000 doesn't match requested rate 8000
  136. 2024-01-21 18:12:25.350731 94.83% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
  137. 2024-01-21 18:12:28.350728 94.73% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/astpp-accountnum.wav
  138. 2024-01-21 18:12:29.310725 94.70% [WARNING] sofia_reg.c:1842 SIP auth challenge (REGISTER) on sofia profile 'default' for [4727985745@pk1betav602.astppbilling.org] from ip 106.206.200.54
  139. 2024-01-21 18:12:29.670726 94.77% [WARNING] sofia_reg.c:1842 SIP auth challenge (INVITE) on sofia profile 'default' for [4727985745@pk1betav602.astppbilling.org] from ip 106.206.200.54
  140. 2024-01-21 18:12:29.770737 94.77% [WARNING] sofia_reg.c:1842 SIP auth challenge (INVITE) on sofia profile 'default' for [90770@pk1betav602.astppbilling.org] from ip 106.206.200.54
  141. 2024-01-21 18:12:32.630729 96.87% [WARNING] sofia_reg.c:1842 SIP auth challenge (INVITE) on sofia profile 'default' for [9815982288@pk1betav602.astppbilling.org] from ip 106.206.200.54
  142. 2024-01-21 18:12:32.750733 96.87% [WARNING] sofia_reg.c:3210 Can't find user [9815982288@pk1betav602.astppbilling.org] from 106.206.200.54
  143. You must define a domain called 'pk1betav602.astppbilling.org' in your directory and add a user with the id="9815982288" attribute
  144. and you must configure your device to use the proper domain in its authentication credentials.
  145. 2024-01-21 18:12:32.890734 96.87% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 4:960
  146. 2024-01-21 18:12:32.890734 96.87% [INFO] switch_channel.c:528 RECV DTMF 4:960
  147. 2024-01-21 18:12:33.470739 96.97% [WARNING] sofia_reg.c:1842 SIP auth challenge (INVITE) on sofia profile 'default' for [9707800844@pk1betav602.astppbilling.org] from ip 106.206.200.54
  148. 2024-01-21 18:12:33.630735 96.97% [WARNING] sofia_reg.c:3210 Can't find user [9707800844@pk1betav602.astppbilling.org] from 106.206.200.54
  149. You must define a domain called 'pk1betav602.astppbilling.org' in your directory and add a user with the id="9707800844" attribute
  150. and you must configure your device to use the proper domain in its authentication credentials.
  151. 2024-01-21 18:12:33.630735 96.97% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 7:960
  152. 2024-01-21 18:12:33.630735 96.97% [INFO] switch_channel.c:528 RECV DTMF 7:960
  153. 2024-01-21 18:12:33.910736 96.97% [WARNING] sofia_reg.c:1842 SIP auth challenge (INVITE) on sofia profile 'default' for [9707820666@pk1betav602.astppbilling.org] from ip 106.206.200.54
  154. 2024-01-21 18:12:34.030736 96.97% [WARNING] sofia_reg.c:3210 Can't find user [9707820666@pk1betav602.astppbilling.org] from 106.206.200.54
  155. You must define a domain called 'pk1betav602.astppbilling.org' in your directory and add a user with the id="9707820666" attribute
  156. and you must configure your device to use the proper domain in its authentication credentials.
  157. 2024-01-21 18:12:35.070735 96.90% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 2:960
  158. 2024-01-21 18:12:35.070735 96.90% [INFO] switch_channel.c:528 RECV DTMF 2:960
  159. 2024-01-21 18:12:35.650726 96.83% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 7:960
  160. 2024-01-21 18:12:35.650726 96.83% [INFO] switch_channel.c:528 RECV DTMF 7:960
  161. 2024-01-21 18:12:37.570729 96.90% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 9:960
  162. 2024-01-21 18:12:37.570729 96.90% [INFO] switch_channel.c:528 RECV DTMF 9:960
  163. 2024-01-21 18:12:38.950727 96.97% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 8:960
  164. 2024-01-21 18:12:38.950727 96.97% [INFO] switch_channel.c:528 RECV DTMF 8:960
  165. 2024-01-21 18:12:40.810730 97.23% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 5:960
  166. 2024-01-21 18:12:40.810730 97.23% [INFO] switch_channel.c:528 RECV DTMF 5:960
  167. 2024-01-21 18:12:41.770728 97.53% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 7:960
  168. 2024-01-21 18:12:41.770728 97.53% [INFO] switch_channel.c:528 RECV DTMF 7:960
  169. 2024-01-21 18:12:43.370736 97.57% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 4:960
  170. 2024-01-21 18:12:43.370736 97.57% [INFO] switch_channel.c:528 RECV DTMF 4:960
  171. 2024-01-21 18:12:43.770732 97.53% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 5:960
  172. 2024-01-21 18:12:43.770732 97.53% [INFO] switch_channel.c:528 RECV DTMF 5:960
  173. 2024-01-21 18:12:44.810716 97.53% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF #:960
  174. span style="color: green; font-weight: bold;"> 2024-01-21 18:12:44.810716 97.53% [INFO] switch_channel.c:528 RECV DTMF #:960
  175. span style="color: goldenrod; font-weight: bold;"> 2024-01-21 18:12:44.810716 97.53% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Got DTMF digits: 4727985745
  176. 2024-01-21 18:12:44.810716 97.53% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT *,(select currencyrate from currency where id=currency_id) as currencyrate FROM accounts WHERE number = "4727985745" AND status=0 AND deleted=0 limit 1
  177. 2024-01-21 18:12:44.830859 97.53% [DEBUG] switch_core_file.c:444 File /usr/local/freeswitch/sounds/en/us/callie/astpp-pleasepin.wav sample rate 16000 doesn't match requested rate 8000
  178. 2024-01-21 18:12:44.830859 97.53% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
  179. 2024-01-21 18:12:47.510728 97.50% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/astpp-pleasepin.wav
  180. 2024-01-21 18:12:48.930735 97.47% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 9:960
  181. 2024-01-21 18:12:48.930735 97.47% [INFO] switch_channel.c:528 RECV DTMF 9:960
  182. 2024-01-21 18:12:49.370725 97.47% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 0:960
  183. 2024-01-21 18:12:49.370725 97.47% [INFO] switch_channel.c:528 RECV DTMF 0:960
  184. 2024-01-21 18:12:49.950727 97.53% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 7:960
  185. 2024-01-21 18:12:49.950727 97.53% [INFO] switch_channel.c:528 RECV DTMF 7:960
  186. 2024-01-21 18:12:50.670768 97.57% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 0:960
  187. 2024-01-21 18:12:50.670768 97.57% [INFO] switch_channel.c:528 RECV DTMF 0:960
  188. 2024-01-21 18:12:51.050725 97.57% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 0:960
  189. 2024-01-21 18:12:51.050725 97.57% [INFO] switch_channel.c:528 RECV DTMF 0:960
  190. 2024-01-21 18:12:51.490733 97.57% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 0:960
  191. 2024-01-21 18:12:51.490733 97.57% [INFO] switch_channel.c:528 RECV DTMF 0:960
  192. 2024-01-21 18:12:52.670731 98.30% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF #:960
  193. span style="color: green; font-weight: bold;"> 2024-01-21 18:12:52.670731 98.30% [INFO] switch_channel.c:528 RECV DTMF #:960
  194. span style="color: goldenrod; font-weight: bold;"> 2024-01-21 18:12:52.670731 98.30% [DEBUG] switch_cpp.cpp:1465 [ASTPP] We Recieved A Pin Number : 907000
  195. 2024-01-21 18:12:52.670731 98.30% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [validate_card_usage] Query :SELECT DATE_FORMAT('2046-07-25 11:26:24' , '%Y%m%d%H%i%s') AS expiry
  196. 2024-01-21 18:12:52.670731 98.30% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [validate_card_usage] Query :SELECT DATE_FORMAT('2024-01-21 18:12:52' , '%Y%m%d%H%i%s') AS expiry
  197. 2024-01-21 18:12:52.670731 98.30% [DEBUG] switch_core_file.c:444 File /usr/local/freeswitch/sounds/en/us/callie/astpp-register.wav sample rate 16000 doesn't match requested rate 8000
  198. 2024-01-21 18:12:52.670731 98.30% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
  199. 2024-01-21 18:12:55.490729 98.50% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/astpp-register.wav
  200. 2024-01-21 18:12:56.010741 98.50% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 1:960
  201. 2024-01-21 18:12:56.010741 98.50% [INFO] switch_channel.c:528 RECV DTMF 1:960
  202. 2024-01-21 18:12:56.010741 98.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [SAVE_ANI] Query :INSERT INTO ani_map (number,accountid,status,creation_date,last_modified_date) VALUES ('4727985745','2',0,'2024-01-21 18:12:56','2024-01-21 18:12:56')
  203. 2024-01-21 18:12:56.010741 98.50% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [Accountcode : 4727985745]
  204. 2024-01-21 18:12:56.010741 98.50% [DEBUG] switch_core_file.c:444 File /usr/local/freeswitch/sounds/en/us/callie/astpp-this-card-has-a-balance-of.wav sample rate 16000 doesn't match requested rate 8000
  205. 2024-01-21 18:12:56.010741 98.50% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
  206. 2024-01-21 18:12:57.330727 98.43% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/astpp-this-card-has-a-balance-of.wav
  207. 2024-01-21 18:12:57.330727 98.43% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [Play Amount First Part] Query :82958
  208. 2024-01-21 18:12:57.330727 98.43% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [Play Amount Second Part] Query :75
  209. EXECUTE [depth=0] sofia/default/4727985745@pk1betav602.astppbilling.org:5078 say(en number pronounced 82958)
  210. 2024-01-21 18:12:57.350752 98.43% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
  211. 2024-01-21 18:13:00.610728 98.43% [DEBUG] switch_ivr_play_say.c:2010 done playing file file_string://digits/80.wav!digits/2.wav!digits/thousand.wav!digits/9.wav!digits/hundred.wav!digits/50.wav!digits/8.wav
  212. 2024-01-21 18:13:00.610728 98.43% [DEBUG] switch_core_file.c:444 File /usr/local/freeswitch/sounds/en/us/callie/astpp-point.wav sample rate 16000 doesn't match requested rate 8000
  213. 2024-01-21 18:13:00.610728 98.43% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
  214. 2024-01-21 18:13:01.170730 98.43% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/astpp-point.wav
  215. EXECUTE [depth=0] sofia/default/4727985745@pk1betav602.astppbilling.org:5078 say(en number pronounced 75)
  216. 2024-01-21 18:13:01.170730 98.43% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
  217. 2024-01-21 18:13:02.490734 96.17% [DEBUG] switch_ivr_play_say.c:2010 done playing file file_string://digits/70.wav!digits/5.wav
  218. 2024-01-21 18:13:02.490734 96.17% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [HP:access_number_call_flow[0:Go Direct Dial,1:Go IVR] : 0]
  219. 2024-01-21 18:13:02.490734 96.17% [DEBUG] switch_core_file.c:444 File /usr/local/freeswitch/sounds/en/us/callie/astpp-phonenum.wav sample rate 16000 doesn't match requested rate 8000
  220. 2024-01-21 18:13:02.490734 96.17% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
  221. 2024-01-21 18:13:06.190729 95.97% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/astpp-phonenum.wav
  222. 2024-01-21 18:13:07.510754 95.97% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 1:960
  223. 2024-01-21 18:13:07.510754 95.97% [INFO] switch_channel.c:528 RECV DTMF 1:960
  224. 2024-01-21 18:13:07.990727 95.97% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 2:960
  225. 2024-01-21 18:13:07.990727 95.97% [INFO] switch_channel.c:528 RECV DTMF 2:960
  226. 2024-01-21 18:13:08.490728 95.90% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 0:960
  227. 2024-01-21 18:13:08.490728 95.90% [INFO] switch_channel.c:528 RECV DTMF 0:960
  228. 2024-01-21 18:13:08.670731 95.90% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 4:960
  229. 2024-01-21 18:13:08.670731 95.90% [INFO] switch_channel.c:528 RECV DTMF 4:960
  230. 2024-01-21 18:13:08.830708 95.90% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 0:960
  231. 2024-01-21 18:13:08.830708 95.90% [INFO] switch_channel.c:528 RECV DTMF 0:960
  232. 2024-01-21 18:13:09.010717 95.90% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 4:960
  233. 2024-01-21 18:13:09.010717 95.90% [INFO] switch_channel.c:528 RECV DTMF 4:960
  234. 2024-01-21 18:13:09.190741 95.90% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 5:960
  235. 2024-01-21 18:13:09.190741 95.90% [INFO] switch_channel.c:528 RECV DTMF 5:960
  236. 2024-01-21 18:13:09.310717 95.90% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 0:960
  237. 2024-01-21 18:13:09.310717 95.90% [INFO] switch_channel.c:528 RECV DTMF 0:960
  238. 2024-01-21 18:13:09.490725 95.90% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 5:960
  239. 2024-01-21 18:13:09.490725 95.90% [INFO] switch_channel.c:528 RECV DTMF 5:960
  240. 2024-01-21 18:13:09.670734 95.90% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 0:960
  241. 2024-01-21 18:13:09.670734 95.90% [INFO] switch_channel.c:528 RECV DTMF 0:960
  242. 2024-01-21 18:13:09.810767 95.90% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 5:960
  243. 2024-01-21 18:13:09.810767 95.90% [INFO] switch_channel.c:528 RECV DTMF 5:960
  244. 2024-01-21 18:13:09.990728 95.90% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 0:960
  245. 2024-01-21 18:13:09.990728 95.90% [INFO] switch_channel.c:528 RECV DTMF 0:960
  246. 2024-01-21 18:13:10.990727 95.90% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF #:960
  247. span style="color: green; font-weight: bold;"> 2024-01-21 18:13:10.990727 95.90% [INFO] switch_channel.c:528 RECV DTMF #:960
  248. span style="color: green; font-weight: bold;"> 2024-01-21 18:13:10.990727 95.90% [INFO] switch_cpp.cpp:1465 [ASTPP] [CHECK Destination] Dialed Destination Number :120404505050
  249. 2024-01-21 18:13:10.990727 95.90% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CHECK_CALL_BARRING] Query :SELECT number,RIGHT(number,1) as lastchar,type as status_type,number_type,accountid FROM call_barring WHERE ((number = '120404505050' OR number = '12040450505' OR number = '1204045050' OR number = '120404505' OR number = '12040450' OR number = '1204045' OR number = '120404' OR number = '12040' OR number = '1204' OR number = '120' OR number = '12' OR number = '1' OR number ='--') OR (number = '120404505050*' OR number = '12040450505*' OR number = '1204045050*' OR number = '120404505*' OR number = '12040450*' OR number = '1204045*' OR number = '120404*' OR number = '12040*' OR number = '1204*' OR number = '120*' OR number = '12*' OR number = '1*' OR number ='--') OR (number = '4727985745' OR number = '472798574' OR number = '47279857' OR number = '4727985' OR number = '472798' OR number = '47279' OR number = '4727' OR number = '472' OR number = '47' OR number = '4' OR number ='--') OR (number = '4727985745*' OR number = '472798574*' OR number = '47279857*' OR number = '4727985*' OR number = '472798*' OR number = '47279*' OR number = '4727*' OR number = '472*' OR number = '47*' OR number = '4*' OR number ='--')) AND status=0 order by LENGTH(number) DESC,lastchar DESC, modified_date DESC
  250. 2024-01-21 18:13:10.990727 95.90% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Call Barring Status : -1
  251. EXECUTE [depth=0] sofia/default/4727985745@pk1betav602.astppbilling.org:5078 set(daily_call_credit_limit=0.00000)
  252. 2024-01-21 18:13:10.990727 95.90% [DEBUG] mod_dptools.c:1671 SET sofia/default/4727985745@pk1betav602.astppbilling.org:5078 [daily_call_credit_limit]=[0.00000]
  253. EXECUTE [depth=0] sofia/default/4727985745@pk1betav602.astppbilling.org:5078 export(daily_call_credit_limit=0.00000)
  254. 2024-01-21 18:13:10.990727 95.90% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [daily_call_credit_limit]=[0.00000]
  255. EXECUTE [depth=0] sofia/default/4727985745@pk1betav602.astppbilling.org:5078 set(daily_call_used_limit=1.40000)
  256. 2024-01-21 18:13:10.990727 95.90% [DEBUG] mod_dptools.c:1671 SET sofia/default/4727985745@pk1betav602.astppbilling.org:5078 [daily_call_used_limit]=[1.40000]
  257. EXECUTE [depth=0] sofia/default/4727985745@pk1betav602.astppbilling.org:5078 export(daily_call_used_limit=1.40000)
  258. 2024-01-21 18:13:10.990727 95.90% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [daily_call_used_limit]=[1.40000]
  259. EXECUTE [depth=0] sofia/default/4727985745@pk1betav602.astppbilling.org:5078 set(monthly_call_credit_limit=1.00000)
  260. 2024-01-21 18:13:10.990727 95.90% [DEBUG] mod_dptools.c:1671 SET sofia/default/4727985745@pk1betav602.astppbilling.org:5078 [monthly_call_credit_limit]=[1.00000]
  261. EXECUTE [depth=0] sofia/default/4727985745@pk1betav602.astppbilling.org:5078 export(monthly_call_credit_limit=1.00000)
  262. 2024-01-21 18:13:10.990727 95.90% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [monthly_call_credit_limit]=[1.00000]
  263. EXECUTE [depth=0] sofia/default/4727985745@pk1betav602.astppbilling.org:5078 set(monthly_call_used_limit=1.40000)
  264. 2024-01-21 18:13:10.990727 95.90% [DEBUG] mod_dptools.c:1671 SET sofia/default/4727985745@pk1betav602.astppbilling.org:5078 [monthly_call_used_limit]=[1.40000]
  265. EXECUTE [depth=0] sofia/default/4727985745@pk1betav602.astppbilling.org:5078 export(monthly_call_used_limit=1.40000)
  266. 2024-01-21 18:13:10.990727 95.90% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [monthly_call_used_limit]=[1.40000]
  267. 2024-01-21 18:13:10.990727 95.90% [DEBUG] switch_cpp.cpp:1465 [ASTPP]  Post Cdrs : 0
  268. 2024-01-21 18:13:10.990727 95.90% [ERR] mod_lua.cpp:202 /usr/local/freeswitch/scripts/astpp/scripts/astpp.xml.lua:930: attempt to concatenate a nil value
  269. stack traceback:
  270.         /usr/local/freeswitch/scripts/astpp/scripts/astpp.xml.lua:930: in function 'xml_header'
  271.        /usr/local/freeswitch/scripts/astpp/scripts/astpp.xml.lua:1111: in function 'error_xml_without_cdr'
  272.         ...switch/scripts/astpp/lib/astpp.callingcard.functions.lua:1009: in function 'process_destination'
  273.         /usr/local/freeswitch/scripts/astpp-callingcards.lua:122: in main chunk
  274. 2024-01-21 18:13:10.990727 95.90% [DEBUG] switch_cpp.cpp:1209 sofia/default/4727985745@pk1betav602.astppbilling.org:5078 destroy/unlink session from object
  275. 2024-01-21 18:13:10.990727 95.90% [NOTICE] switch_core_state_machine.c:382 sofia/default/4727985745@pk1betav602.astppbilling.org:5078 has executed the last dialplan instruction, hanging up.
  276. 2024-01-21 18:13:10.990727 95.90% [NOTICE] switch_core_state_machine.c:384 Hangup sofia/default/4727985745@pk1betav602.astppbilling.org:5078 [CS_EXECUTE] [NORMAL_CLEARING]
  277. 2024-01-21 18:13:10.990727 95.90% [DEBUG] switch_core_state_machine.c:647 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) State EXECUTE going to sleep
  278. 2024-01-21 18:13:10.990727 95.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) Running State Change CS_HANGUP (Cur 1 Tot 16)
  279. 2024-01-21 18:13:10.990727 95.90% [DEBUG] switch_core_state_machine.c:844 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) Callstate Change ACTIVE -> HANGUP
  280. 2024-01-21 18:13:10.990727 95.90% [DEBUG] switch_core_state_machine.c:846 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) State HANGUP
  281. 2024-01-21 18:13:10.990727 95.90% [DEBUG] mod_sofia.c:469 Channel sofia/default/4727985745@pk1betav602.astppbilling.org:5078 hanging up, cause: NORMAL_CLEARING
  282. 2024-01-21 18:13:10.990727 95.90% [DEBUG] mod_sofia.c:523 Sending BYE to sofia/default/4727985745@pk1betav602.astppbilling.org:5078
  283. 2024-01-21 18:13:10.990727 95.90% [DEBUG] switch_core_state_machine.c:59 sofia/default/4727985745@pk1betav602.astppbilling.org:5078 Standard HANGUP, cause: NORMAL_CLEARING
  284. 2024-01-21 18:13:10.990727 95.90% [DEBUG] switch_core_state_machine.c:846 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) State HANGUP going to sleep
  285. 2024-01-21 18:13:10.990727 95.90% [DEBUG] switch_core_state_machine.c:616 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) State Change CS_HANGUP -> CS_REPORTING
  286. 2024-01-21 18:13:10.990727 95.90% [DEBUG] switch_core_state_machine.c:581 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) Running State Change CS_REPORTING (Cur 1 Tot 16)
  287. 2024-01-21 18:13:10.990727 95.90% [DEBUG] switch_core_state_machine.c:932 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) State REPORTING
  288. 2024-01-21 18:13:10.990727 95.90% [INFO] mod_json_cdr.c:272 Process [0a41f4c0-85cd-4d42-9918-f85d60f90de5.cdr.json]
  289. 2024-01-21 18:13:10.990727 95.90% [DEBUG] switch_core_state_machine.c:168 sofia/default/4727985745@pk1betav602.astppbilling.org:5078 Standard REPORTING, cause: NORMAL_CLEARING
  290. 2024-01-21 18:13:10.990727 95.90% [DEBUG] switch_core_state_machine.c:932 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) State REPORTING going to sleep
  291. 2024-01-21 18:13:10.990727 95.90% [DEBUG] switch_core_state_machine.c:607 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) State Change CS_REPORTING -> CS_DESTROY
  292. 2024-01-21 18:13:10.990727 95.90% [DEBUG] switch_core_session.c:1744 Session 16 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) Locked, Waiting on external entities
  293. 2024-01-21 18:13:10.990727 95.90% [NOTICE] switch_core_session.c:1762 Session 16 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) Ended
  294. 2024-01-21 18:13:10.990727 95.90% [NOTICE] switch_core_session.c:1766 Close Channel sofia/default/4727985745@pk1betav602.astppbilling.org:5078 [CS_DESTROY]
  295. 2024-01-21 18:13:10.990727 95.90% [DEBUG] switch_core_state_machine.c:735 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) Running State Change CS_DESTROY (Cur 0 Tot 16)
  296. 2024-01-21 18:13:10.990727 95.90% [DEBUG] switch_core_state_machine.c:745 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) State DESTROY
  297. 2024-01-21 18:13:10.990727 95.90% [DEBUG] mod_sofia.c:380 sofia/default/4727985745@pk1betav602.astppbilling.org:5078 SOFIA DESTROY
  298. 2024-01-21 18:13:10.990727 95.90% [DEBUG] switch_core_state_machine.c:175 sofia/default/4727985745@pk1betav602.astppbilling.org:5078 Standard DESTROY
  299. 2024-01-21 18:13:10.990727 95.90% [DEBUG] switch_core_state_machine.c:745 (sofia/default/4727985745@pk1betav602.astppbilling.org:5078) State DESTROY going to sleep
  300.