FreeSWITCH Pastebin

error in fs_cli log during Call by Calling card

From Prashant Kumar, 1 Month ago, written in FreeSWITCH.
- go back
URL https://pastebin.freeswitch.org/view/20d5c0b1
Embed
Viewing differences between and error in fs_cli log during Call by Calling card
  1.  
  2. [This app Best viewed at 160x60 or more..]
  3. +OK log level  [7]
  4. freeswitch@GuiOsip1ClusterQa-Alpesh>
  5. freeswitch@GuiOsip1ClusterQa-Alpesh>
  6. 2024-11-29 06:31:21.002700 88.00% [NOTICE] switch_channel.c:1142 New Channel sofia/default/10001@78.47.101.152 [5cfc03e4-4220-4f1d-85b6-566a4943dae4]
  7. 2024-11-29 06:31:21.002700 88.00% [DEBUG] switch_core_state_machine.c:581 (sofia/default/10001@78.47.101.152) Running State Change CS_NEW (Cur 1 Tot 1675)
  8. 2024-11-29 06:31:21.002700 88.00% [INFO] sofia.c:10459 sofia/default/10001@78.47.101.152 receiving invite from 185.243.5.117:62646 version: 1.10.10-release  64bit call-id: 2011262641-1253501920-782237107
  9. 2024-11-29 06:31:21.002700 88.00% [DEBUG] sofia.c:10553 verifying acl "default" for ip/port 185.243.5.117:0.
  10. 2024-11-29 06:31:21.002700 88.00% [WARNING] sofia_reg.c:1842 SIP auth challenge (INVITE) on sofia profile 'default' for [241800442037694006@78.47.101.152] from ip 185.243.5.117
  11. 2024-11-29 06:31:21.002700 88.00% [DEBUG] switch_core_state_machine.c:600 (sofia/default/10001@78.47.101.152) State NEW
  12. 2024-11-29 06:31:21.002700 88.00% [DEBUG] sofia.c:2419 detaching session 5cfc03e4-4220-4f1d-85b6-566a4943dae4
  13. 2024-11-29 06:31:21.102770 88.00% [NOTICE] switch_channel.c:1142 New Channel sofia/default/10001@78.47.101.152 [fee1d934-d52e-4c07-a975-64f140cae7e0]
  14. 2024-11-29 06:31:21.102770 88.00% [DEBUG] switch_core_state_machine.c:581 (sofia/default/10001@78.47.101.152) Running State Change CS_NEW (Cur 2 Tot 1676)
  15. 2024-11-29 06:31:21.102770 88.00% [INFO] sofia.c:10459 sofia/default/10001@78.47.101.152 receiving invite from 185.243.5.117:62816 version: 1.10.10-release  64bit call-id: 27965023-508711504-764764425
  16. 2024-11-29 06:31:21.102770 88.00% [DEBUG] sofia.c:10553 verifying acl "default" for ip/port 185.243.5.117:0.
  17. 2024-11-29 06:31:21.102770 88.00% [WARNING] sofia_reg.c:1842 SIP auth challenge (INVITE) on sofia profile 'default' for [649006441519470522@78.47.101.152] from ip 185.243.5.117
  18. 2024-11-29 06:31:21.102770 88.00% [DEBUG] switch_core_state_machine.c:600 (sofia/default/10001@78.47.101.152) State NEW
  19. 2024-11-29 06:31:21.102770 88.00% [DEBUG] sofia.c:2419 detaching session fee1d934-d52e-4c07-a975-64f140cae7e0
  20. 2024-11-29 06:31:21.822728 88.00% [NOTICE] switch_channel.c:1142 New Channel sofia/default/1187009497@astppdemo.astppbilling.org [2992c2f2-dfcd-4b04-b9e0-cbc1583cccee]
  21. 2024-11-29 06:31:21.822728 88.00% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1187009497@astppdemo.astppbilling.org) Running State Change CS_NEW (Cur 3 Tot 1677)
  22. 2024-11-29 06:31:21.822728 88.00% [INFO] sofia.c:10459 sofia/default/1187009497@astppdemo.astppbilling.org receiving invite from 152.58.158.186:14470 version: 1.10.10-release  64bit call-id: Y2ZmNjFmMGI4MzAyZGVjOWYxM2IwNjMwNzhhNTMxZTg.
  23. 2024-11-29 06:31:21.822728 88.00% [DEBUG] sofia.c:10553 verifying acl "default" for ip/port 152.58.158.186:0.
  24. 2024-11-29 06:31:21.822728 88.00% [WARNING] sofia_reg.c:1842 SIP auth challenge (INVITE) on sofia profile 'default' for [444555@astppdemo.astppbilling.org] from ip 152.58.158.186
  25. 2024-11-29 06:31:21.822728 88.00% [DEBUG] switch_core_state_machine.c:600 (sofia/default/1187009497@astppdemo.astppbilling.org) State NEW
  26. 2024-11-29 06:31:21.822728 88.00% [DEBUG] sofia.c:2419 detaching session 2992c2f2-dfcd-4b04-b9e0-cbc1583cccee
  27. 2024-11-29 06:31:22.742697 88.00% [DEBUG] sofia.c:2532 Re-attaching to session 2992c2f2-dfcd-4b04-b9e0-cbc1583cccee
  28. 2024-11-29 06:31:22.742697 88.00% [INFO] sofia.c:10459 sofia/default/1187009497@astppdemo.astppbilling.org receiving invite from 152.58.158.186:14470 version: 1.10.10-release  64bit call-id: Y2ZmNjFmMGI4MzAyZGVjOWYxM2IwNjMwNzhhNTMxZTg.
  29. 2024-11-29 06:31:22.742697 88.00% [DEBUG] sofia.c:10553 verifying acl "default" for ip/port 152.58.158.186:0.
  30. 2024-11-29 06:31:22.782697 88.00% [DEBUG] sofia.c:11674 Setting NAT mode based on via port
  31. 2024-11-29 06:31:22.782697 88.00% [DEBUG] sofia.c:7493 Channel sofia/default/1187009497@astppdemo.astppbilling.org entering state [received][100]
  32. 2024-11-29 06:31:22.782697 88.00% [DEBUG] sofia.c:7503 Remote SDP:
  33. v=0
  34. o=Z 0 0 IN IP4 152.58.158.186
  35. s=Z
  36. c=IN IP4 152.58.158.186
  37. t=0 0
  38. m=audio 8000 RTP/AVP 3 110 8 0 98 101
  39. a=rtpmap:110 speex/8000
  40. a=rtpmap:98 iLBC/8000
  41. a=fmtp:98 mode=20
  42. a=rtpmap:101 telephone-event/8000
  43. a=fmtp:101 0-15
  44.  
  45. 2024-11-29 06:31:22.782697 88.00% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
  46. 2024-11-29 06:31:22.782697 88.00% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
  47. 2024-11-29 06:31:22.782697 88.00% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [speex:110:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
  48. 2024-11-29 06:31:22.782697 88.00% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [speex:110:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
  49. 2024-11-29 06:31:22.782697 88.00% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  50. 2024-11-29 06:31:22.782697 88.00% [DEBUG] switch_core_media.c:5588 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  51. 2024-11-29 06:31:22.782697 88.00% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  52. 2024-11-29 06:31:22.782697 88.00% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  53. 2024-11-29 06:31:22.782697 88.00% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  54. 2024-11-29 06:31:22.782697 88.00% [DEBUG] switch_core_media.c:5588 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  55. 2024-11-29 06:31:22.782697 88.00% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [iLBC:98:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
  56. 2024-11-29 06:31:22.782697 88.00% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [iLBC:98:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
  57. 2024-11-29 06:31:22.782697 88.00% [DEBUG] switch_core_media.c:5438 Set telephone-event payload to 101@8000
  58. 2024-11-29 06:31:22.782697 88.00% [DEBUG] switch_core_media.c:3734 Set Codec sofia/default/1187009497@astppdemo.astppbilling.org PCMA/8000 20 ms 160 samples 64000 bits 1 channels
  59. 2024-11-29 06:31:22.782697 88.00% [DEBUG] switch_core_codec.c:111 sofia/default/1187009497@astppdemo.astppbilling.org Original read codec set to PCMA:8
  60. 2024-11-29 06:31:22.782697 88.00% [DEBUG] switch_core_media.c:5798 Set telephone-event payload to 101@8000
  61. 2024-11-29 06:31:22.782697 88.00% [DEBUG] switch_core_media.c:5856 sofia/default/1187009497@astppdemo.astppbilling.org Set 2833 dtmf send payload to 101 recv payload to 101
  62. 2024-11-29 06:31:22.782697 88.00% [DEBUG] sofia.c:7927 (sofia/default/1187009497@astppdemo.astppbilling.org) State Change CS_NEW -> CS_INIT
  63. 2024-11-29 06:31:22.782697 88.00% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1187009497@astppdemo.astppbilling.org) Running State Change CS_INIT (Cur 3 Tot 1677)
  64. 2024-11-29 06:31:22.782697 88.00% [DEBUG] switch_core_state_machine.c:624 (sofia/default/1187009497@astppdemo.astppbilling.org) State INIT
  65. 2024-11-29 06:31:22.782697 88.00% [DEBUG] mod_sofia.c:97 sofia/default/1187009497@astppdemo.astppbilling.org SOFIA INIT
  66. 2024-11-29 06:31:22.782697 88.00% [DEBUG] switch_core_state_machine.c:40 sofia/default/1187009497@astppdemo.astppbilling.org Standard INIT
  67. 2024-11-29 06:31:22.782697 88.00% [DEBUG] switch_core_state_machine.c:48 (sofia/default/1187009497@astppdemo.astppbilling.org) State Change CS_INIT -> CS_ROUTING
  68. 2024-11-29 06:31:22.782697 88.00% [DEBUG] switch_core_state_machine.c:624 (sofia/default/1187009497@astppdemo.astppbilling.org) State INIT going to sleep
  69. 2024-11-29 06:31:22.782697 88.00% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1187009497@astppdemo.astppbilling.org) Running State Change CS_ROUTING (Cur 3 Tot 1677)
  70. 2024-11-29 06:31:22.782697 88.00% [DEBUG] switch_channel.c:2399 (sofia/default/1187009497@astppdemo.astppbilling.org) Callstate Change DOWN -> RINGING
  71. 2024-11-29 06:31:22.782697 88.00% [DEBUG] switch_core_state_machine.c:640 (sofia/default/1187009497@astppdemo.astppbilling.org) State ROUTING
  72. 2024-11-29 06:31:22.782697 88.00% [DEBUG] mod_sofia.c:158 sofia/default/1187009497@astppdemo.astppbilling.org SOFIA ROUTING
  73. 2024-11-29 06:31:22.782697 88.00% [DEBUG] switch_core_state_machine.c:230 sofia/default/1187009497@astppdemo.astppbilling.org Standard ROUTING
  74. 2024-11-29 06:31:22.782697 88.00% [INFO] mod_dialplan_xml.c:639 Processing 1187009497 <1187009497>->444555 in context default
  75. 2024-11-29 06:31:22.802700 88.00% [INFO] switch_cpp.cpp:1465 [ASTPP] USING CACHE
  76. 2024-11-29 06:31:22.802700 88.00% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_SYSTEM]1.0
  77. 2024-11-29 06:31:22.802700 88.00% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_SYSTEM]1.0
  78. 2024-11-29 06:31:22.802700 88.00% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
  79. 2024-11-29 06:31:22.822698 88.00% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] Dialed number : 444555
  80. 2024-11-29 06:31:22.822698 88.00% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_ACCESS_NUMBER]1.0
  81. 2024-11-29 06:31:22.822698 88.00% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_ACCESS_NUMBER]1.1
  82. 2024-11-29 06:31:22.822698 88.00% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_ACCESS_NUMBER]1.2 :: CALL IS ACCESS NUMBER
  83. 2024-11-29 06:31:22.822698 88.00% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Generated XML:
  84. <?xml version="1.0" encoding="UTF-8" standalone="no"?>
  85. <document type="freeswitch/xml">
  86. <section name="dialplan" description="ASTPP Dialplan">
  87. <context name="default">
  88. <extension name="444555">
  89. <condition field="destination_number" expression="444555">
  90. <action application="log" data="INFO ASTPP - Calling Card Call"/>
  91. <action application="answer"/>
  92. <action application="sleep" data="2000"/>
  93. <action application="lua" data="astpp-callingcards.lua"/>
  94. </condition>
  95. </extension>
  96. </context>
  97. </section>
  98. </document>
  99. Dialplan: sofia/default/1187009497@astppdemo.astppbilling.org parsing [default->444555] continue=false
  100. Dialplan: sofia/default/1187009497@astppdemo.astppbilling.org Regex (PASS) [444555] destination_number(444555) =~ /444555/ break=on-false
  101. Dialplan: sofia/default/1187009497@astppdemo.astppbilling.org Action log(INFO ASTPP - Calling Card Call)
  102. Dialplan: sofia/default/1187009497@astppdemo.astppbilling.org Action answer()
  103. Dialplan: sofia/default/1187009497@astppdemo.astppbilling.org Action sleep(2000)
  104. Dialplan: sofia/default/1187009497@astppdemo.astppbilling.org Action lua(astpp-callingcards.lua)
  105. 2024-11-29 06:31:22.822698 88.00% [DEBUG] switch_core_state_machine.c:281 (sofia/default/1187009497@astppdemo.astppbilling.org) State Change CS_ROUTING -> CS_EXECUTE
  106. 2024-11-29 06:31:22.822698 88.00% [DEBUG] switch_core_state_machine.c:640 (sofia/default/1187009497@astppdemo.astppbilling.org) State ROUTING going to sleep
  107. 2024-11-29 06:31:22.822698 88.00% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1187009497@astppdemo.astppbilling.org) Running State Change CS_EXECUTE (Cur 3 Tot 1677)
  108. 2024-11-29 06:31:22.822698 88.00% [DEBUG] switch_core_state_machine.c:647 (sofia/default/1187009497@astppdemo.astppbilling.org) State EXECUTE
  109. 2024-11-29 06:31:22.822698 88.00% [DEBUG] mod_sofia.c:213 sofia/default/1187009497@astppdemo.astppbilling.org SOFIA EXECUTE
  110. 2024-11-29 06:31:22.822698 88.00% [DEBUG] switch_core_state_machine.c:323 sofia/default/1187009497@astppdemo.astppbilling.org Standard EXECUTE
  111. EXECUTE [depth=0] sofia/default/1187009497@astppdemo.astppbilling.org log(INFO ASTPP - Calling Card Call)
  112. 2024-11-29 06:31:22.822698 88.00% [INFO] mod_dptools.c:1865 ASTPP - Calling Card Call
  113. EXECUTE [depth=0] sofia/default/1187009497@astppdemo.astppbilling.org answer()
  114. 2024-11-29 06:31:22.822698 88.00% [DEBUG] switch_core_media.c:8659 AUDIO RTP [sofia/default/1187009497@astppdemo.astppbilling.org] 78.47.101.152 port 26580 -> 152.58.158.186 port 8000 codec: 8 ms: 20
  115. 2024-11-29 06:31:22.822698 88.00% [DEBUG] switch_rtp.c:4373 Starting timer [soft] 160 bytes per 20ms
  116. 2024-11-29 06:31:22.822698 88.00% [DEBUG] switch_core_media.c:8972 sofia/default/1187009497@astppdemo.astppbilling.org Set 2833 dtmf send payload to 101
  117. 2024-11-29 06:31:22.822698 88.00% [DEBUG] switch_core_media.c:8979 sofia/default/1187009497@astppdemo.astppbilling.org Set 2833 dtmf receive payload to 101
  118. 2024-11-29 06:31:22.822698 88.00% [DEBUG] switch_core_media.c:9002 sofia/default/1187009497@astppdemo.astppbilling.org Set rtp dtmf delay to 40
  119. 2024-11-29 06:31:22.822698 88.00% [DEBUG] mod_sofia.c:914 Local SDP sofia/default/1187009497@astppdemo.astppbilling.org:
  120. v=0
  121. o=FreeSWITCH 1732835302 1732835303 IN IP4 78.47.101.152
  122. s=FreeSWITCH
  123. c=IN IP4 78.47.101.152
  124. t=0 0
  125. m=audio 26580 RTP/AVP 8 101
  126. a=rtpmap:8 PCMA/8000
  127. a=rtpmap:101 telephone-event/8000
  128. a=fmtp:101 0-15
  129. a=ptime:20
  130. a=sendrecv
  131.  
  132. 2024-11-29 06:31:22.822698 88.00% [NOTICE] mod_dptools.c:1406 Channel [sofia/default/1187009497@astppdemo.astppbilling.org] has been answered
  133. 2024-11-29 06:31:22.822698 88.00% [DEBUG] switch_channel.c:3912 (sofia/default/1187009497@astppdemo.astppbilling.org) Callstate Change RINGING -> ACTIVE
  134. 2024-11-29 06:31:22.822698 88.00% [DEBUG] sofia.c:7493 Channel sofia/default/1187009497@astppdemo.astppbilling.org entering state [completed][200]
  135. EXECUTE [depth=0] sofia/default/1187009497@astppdemo.astppbilling.org sleep(2000)
  136. 2024-11-29 06:31:23.083123 87.87% [DEBUG] sofia.c:7493 Channel sofia/default/1187009497@astppdemo.astppbilling.org entering state [ready][200]
  137. 2024-11-29 06:31:23.083123 87.87% [DEBUG] switch_rtp.c:7503 Correct audio ip/port confirmed.
  138. EXECUTE [depth=0] sofia/default/1187009497@astppdemo.astppbilling.org lua(astpp-callingcards.lua)
  139. 2024-11-29 06:31:24.862731 87.77% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_SYSTEM]1.0
  140. 2024-11-29 06:31:24.862731 87.77% [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','vanity_number')
  141. 2024-11-29 06:31:24.862731 87.77% [NOTICE] switch_cpp.cpp:1465 [ASTPP] SECTION
  142. 2024-11-29 06:31:24.862731 87.77% [DEBUG] switch_core_file.c:444 File /var/www/html/astpp/upload/astpp-welcome.wav sample rate 16000 doesn't match requested rate 8000
  143. 2024-11-29 06:31:24.862731 87.77% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
  144. 2024-11-29 06:31:26.642747 87.83% [DEBUG] switch_ivr_play_say.c:2010 done playing file /var/www/html/astpp/upload/astpp-welcome.wav
  145. 2024-11-29 06:31:26.642747 87.83% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [get_ani] Query :SELECT * FROM ani_map WHERE number = 1187009497
  146. 2024-11-29 06:31:26.642747 87.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
  147. 2024-11-29 06:31:26.642747 87.83% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
  148. 2024-11-29 06:31:29.642741 88.10% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/astpp-accountnum.wav
  149. 2024-11-29 06:31:31.042705 88.30% [WARNING] switch_core_state_machine.c:684 5cfc03e4-4220-4f1d-85b6-566a4943dae4 sofia/default/10001@78.47.101.152 Abandoned
  150. 2024-11-29 06:31:31.042705 88.30% [NOTICE] switch_core_state_machine.c:687 Hangup sofia/default/10001@78.47.101.152 [CS_NEW] [WRONG_CALL_STATE]
  151. 2024-11-29 06:31:31.042705 88.30% [DEBUG] switch_core_state_machine.c:581 (sofia/default/10001@78.47.101.152) Running State Change CS_HANGUP (Cur 3 Tot 1677)
  152. 2024-11-29 06:31:31.042705 88.30% [DEBUG] switch_core_state_machine.c:844 (sofia/default/10001@78.47.101.152) Callstate Change DOWN -> HANGUP
  153. 2024-11-29 06:31:31.042705 88.30% [DEBUG] switch_core_state_machine.c:846 (sofia/default/10001@78.47.101.152) State HANGUP
  154. 2024-11-29 06:31:31.042705 88.30% [DEBUG] mod_sofia.c:469 Channel sofia/default/10001@78.47.101.152 hanging up, cause: WRONG_CALL_STATE
  155. 2024-11-29 06:31:31.042705 88.30% [DEBUG] switch_core_state_machine.c:59 sofia/default/10001@78.47.101.152 Standard HANGUP, cause: WRONG_CALL_STATE
  156. 2024-11-29 06:31:31.042705 88.30% [DEBUG] switch_core_state_machine.c:846 (sofia/default/10001@78.47.101.152) State HANGUP going to sleep
  157. 2024-11-29 06:31:31.042705 88.30% [DEBUG] switch_core_state_machine.c:616 (sofia/default/10001@78.47.101.152) State Change CS_HANGUP -> CS_REPORTING
  158. 2024-11-29 06:31:31.042705 88.30% [DEBUG] switch_core_state_machine.c:581 (sofia/default/10001@78.47.101.152) Running State Change CS_REPORTING (Cur 3 Tot 1677)
  159. 2024-11-29 06:31:31.042705 88.30% [DEBUG] switch_core_state_machine.c:932 (sofia/default/10001@78.47.101.152) State REPORTING
  160. 2024-11-29 06:31:31.042705 88.30% [DEBUG] switch_core_state_machine.c:168 sofia/default/10001@78.47.101.152 Standard REPORTING, cause: WRONG_CALL_STATE
  161. 2024-11-29 06:31:31.042705 88.30% [DEBUG] switch_core_state_machine.c:932 (sofia/default/10001@78.47.101.152) State REPORTING going to sleep
  162. 2024-11-29 06:31:31.042705 88.30% [DEBUG] switch_core_state_machine.c:607 (sofia/default/10001@78.47.101.152) State Change CS_REPORTING -> CS_DESTROY
  163. 2024-11-29 06:31:31.042705 88.30% [DEBUG] switch_core_session.c:1744 Session 1675 (sofia/default/10001@78.47.101.152) Locked, Waiting on external entities
  164. 2024-11-29 06:31:31.042705 88.30% [NOTICE] switch_core_session.c:1762 Session 1675 (sofia/default/10001@78.47.101.152) Ended
  165. 2024-11-29 06:31:31.042705 88.30% [NOTICE] switch_core_session.c:1766 Close Channel sofia/default/10001@78.47.101.152 [CS_DESTROY]
  166. 2024-11-29 06:31:31.042705 88.30% [DEBUG] switch_core_state_machine.c:735 (sofia/default/10001@78.47.101.152) Running State Change CS_DESTROY (Cur 2 Tot 1677)
  167. 2024-11-29 06:31:31.042705 88.30% [DEBUG] switch_core_state_machine.c:745 (sofia/default/10001@78.47.101.152) State DESTROY
  168. 2024-11-29 06:31:31.042705 88.30% [DEBUG] mod_sofia.c:380 sofia/default/10001@78.47.101.152 SOFIA DESTROY
  169. 2024-11-29 06:31:31.042705 88.30% [DEBUG] switch_core_state_machine.c:175 sofia/default/10001@78.47.101.152 Standard DESTROY
  170. 2024-11-29 06:31:31.042705 88.30% [DEBUG] switch_core_state_machine.c:745 (sofia/default/10001@78.47.101.152) State DESTROY going to sleep
  171. 2024-11-29 06:31:31.142755 88.30% [WARNING] switch_core_state_machine.c:684 fee1d934-d52e-4c07-a975-64f140cae7e0 sofia/default/10001@78.47.101.152 Abandoned
  172. 2024-11-29 06:31:31.142755 88.30% [NOTICE] switch_core_state_machine.c:687 Hangup sofia/default/10001@78.47.101.152 [CS_NEW] [WRONG_CALL_STATE]
  173. 2024-11-29 06:31:31.142755 88.30% [DEBUG] switch_core_state_machine.c:581 (sofia/default/10001@78.47.101.152) Running State Change CS_HANGUP (Cur 2 Tot 1677)
  174. 2024-11-29 06:31:31.142755 88.30% [DEBUG] switch_core_state_machine.c:844 (sofia/default/10001@78.47.101.152) Callstate Change DOWN -> HANGUP
  175. 2024-11-29 06:31:31.142755 88.30% [DEBUG] switch_core_state_machine.c:846 (sofia/default/10001@78.47.101.152) State HANGUP
  176. 2024-11-29 06:31:31.142755 88.30% [DEBUG] mod_sofia.c:469 Channel sofia/default/10001@78.47.101.152 hanging up, cause: WRONG_CALL_STATE
  177. 2024-11-29 06:31:31.142755 88.30% [DEBUG] switch_core_state_machine.c:59 sofia/default/10001@78.47.101.152 Standard HANGUP, cause: WRONG_CALL_STATE
  178. 2024-11-29 06:31:31.142755 88.30% [DEBUG] switch_core_state_machine.c:846 (sofia/default/10001@78.47.101.152) State HANGUP going to sleep
  179. 2024-11-29 06:31:31.142755 88.30% [DEBUG] switch_core_state_machine.c:616 (sofia/default/10001@78.47.101.152) State Change CS_HANGUP -> CS_REPORTING
  180. 2024-11-29 06:31:31.142755 88.30% [DEBUG] switch_core_state_machine.c:581 (sofia/default/10001@78.47.101.152) Running State Change CS_REPORTING (Cur 2 Tot 1677)
  181. 2024-11-29 06:31:31.142755 88.30% [DEBUG] switch_core_state_machine.c:932 (sofia/default/10001@78.47.101.152) State REPORTING
  182. 2024-11-29 06:31:31.142755 88.30% [DEBUG] switch_core_state_machine.c:168 sofia/default/10001@78.47.101.152 Standard REPORTING, cause: WRONG_CALL_STATE
  183. 2024-11-29 06:31:31.142755 88.30% [DEBUG] switch_core_state_machine.c:932 (sofia/default/10001@78.47.101.152) State REPORTING going to sleep
  184. 2024-11-29 06:31:31.142755 88.30% [DEBUG] switch_core_state_machine.c:607 (sofia/default/10001@78.47.101.152) State Change CS_REPORTING -> CS_DESTROY
  185. 2024-11-29 06:31:31.142755 88.30% [DEBUG] switch_core_session.c:1744 Session 1676 (sofia/default/10001@78.47.101.152) Locked, Waiting on external entities
  186. 2024-11-29 06:31:31.142755 88.30% [NOTICE] switch_core_session.c:1762 Session 1676 (sofia/default/10001@78.47.101.152) Ended
  187. 2024-11-29 06:31:31.142755 88.30% [NOTICE] switch_core_session.c:1766 Close Channel sofia/default/10001@78.47.101.152 [CS_DESTROY]
  188. 2024-11-29 06:31:31.142755 88.30% [DEBUG] switch_core_state_machine.c:735 (sofia/default/10001@78.47.101.152) Running State Change CS_DESTROY (Cur 1 Tot 1677)
  189. 2024-11-29 06:31:31.142755 88.30% [DEBUG] switch_core_state_machine.c:745 (sofia/default/10001@78.47.101.152) State DESTROY
  190. 2024-11-29 06:31:31.142755 88.30% [DEBUG] mod_sofia.c:380 sofia/default/10001@78.47.101.152 SOFIA DESTROY
  191. 2024-11-29 06:31:31.142755 88.30% [DEBUG] switch_core_state_machine.c:175 sofia/default/10001@78.47.101.152 Standard DESTROY
  192. 2024-11-29 06:31:31.142755 88.30% [DEBUG] switch_core_state_machine.c:745 (sofia/default/10001@78.47.101.152) State DESTROY going to sleep
  193. 2024-11-29 06:31:33.842756 91.47% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 4:960
  194. 2024-11-29 06:31:33.842756 91.47% [INFO] switch_channel.c:528 RECV DTMF 4:960
  195. 2024-11-29 06:31:34.262764 91.73% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 7:960
  196. 2024-11-29 06:31:34.262764 91.73% [INFO] switch_channel.c:528 RECV DTMF 7:960
  197. 2024-11-29 06:31:34.722742 91.73% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 2:960
  198. 2024-11-29 06:31:34.722742 91.73% [INFO] switch_channel.c:528 RECV DTMF 2:960
  199. 2024-11-29 06:31:35.442719 91.83% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 7:960
  200. 2024-11-29 06:31:35.442719 91.83% [INFO] switch_channel.c:528 RECV DTMF 7:960
  201. 2024-11-29 06:31:36.162770 91.67% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 9:960
  202. 2024-11-29 06:31:36.162770 91.67% [INFO] switch_channel.c:528 RECV DTMF 9:960
  203. 2024-11-29 06:31:36.502747 91.67% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 8:960
  204. 2024-11-29 06:31:36.502747 91.67% [INFO] switch_channel.c:528 RECV DTMF 8:960
  205. 2024-11-29 06:31:37.282705 91.90% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 5:960
  206. 2024-11-29 06:31:37.282705 91.90% [INFO] switch_channel.c:528 RECV DTMF 5:960
  207. 2024-11-29 06:31:38.442724 91.83% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 7:960
  208. 2024-11-29 06:31:38.442724 91.83% [INFO] switch_channel.c:528 RECV DTMF 7:960
  209. 2024-11-29 06:31:39.262713 91.93% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 4:960
  210. 2024-11-29 06:31:39.262713 91.93% [INFO] switch_channel.c:528 RECV DTMF 4:960
  211. 2024-11-29 06:31:39.482750 91.93% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 5:960
  212. 2024-11-29 06:31:39.482750 91.93% [INFO] switch_channel.c:528 RECV DTMF 5:960
  213. 2024-11-29 06:31:40.982721 91.97% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF #:960
  214. span style="color: green; font-weight: bold;"> 2024-11-29 06:31:40.982721 91.97% [INFO] switch_channel.c:528 RECV DTMF #:960
  215. span style="color: goldenrod; font-weight: bold;"> 2024-11-29 06:31:40.982721 91.97% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Got DTMF digits: 4727985745
  216. 2024-11-29 06:31:40.982721 91.97% [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
  217. 2024-11-29 06:31:41.002741 91.97% [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
  218. 2024-11-29 06:31:41.002741 91.97% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
  219. 2024-11-29 06:31:43.522726 91.97% [NOTICE] switch_channel.c:1142 New Channel sofia/default/1001@78.47.101.152 [cb9b034f-d23a-465e-91e9-c4d69b5f4f4b]
  220. 2024-11-29 06:31:43.522726 91.97% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1001@78.47.101.152) Running State Change CS_NEW (Cur 2 Tot 1678)
  221. 2024-11-29 06:31:43.522726 91.97% [INFO] sofia.c:10459 sofia/default/1001@78.47.101.152 receiving invite from 185.243.5.115:57302 version: 1.10.10-release  64bit call-id: 1060202663-326072009-1074538612
  222. 2024-11-29 06:31:43.522726 91.97% [DEBUG] sofia.c:10553 verifying acl "default" for ip/port 185.243.5.115:0.
  223. 2024-11-29 06:31:43.522726 91.97% [WARNING] sofia_reg.c:1842 SIP auth challenge (INVITE) on sofia profile 'default' for [18090012156085143@78.47.101.152] from ip 185.243.5.115
  224. 2024-11-29 06:31:43.522726 91.97% [DEBUG] switch_core_state_machine.c:600 (sofia/default/1001@78.47.101.152) State NEW
  225. 2024-11-29 06:31:43.522726 91.97% [DEBUG] sofia.c:2419 detaching session cb9b034f-d23a-465e-91e9-c4d69b5f4f4b
  226. 2024-11-29 06:31:43.702713 91.97% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/astpp-pleasepin.wav
  227. 2024-11-29 06:31:44.762758 92.07% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 4:960
  228. 2024-11-29 06:31:44.762758 92.07% [INFO] switch_channel.c:528 RECV DTMF 4:960
  229. 2024-11-29 06:31:45.202765 91.97% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 7:960
  230. 2024-11-29 06:31:45.202765 91.97% [INFO] switch_channel.c:528 RECV DTMF 7:960
  231. 2024-11-29 06:31:45.762727 91.97% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 2:960
  232. 2024-11-29 06:31:45.762727 91.97% [INFO] switch_channel.c:528 RECV DTMF 2:960
  233. 2024-11-29 06:31:46.222690 91.97% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 7:960
  234. 2024-11-29 06:31:46.222690 91.97% [INFO] switch_channel.c:528 RECV DTMF 7:960
  235. 2024-11-29 06:31:47.062792 92.10% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 9:960
  236. 2024-11-29 06:31:47.062792 92.10% [INFO] switch_channel.c:528 RECV DTMF 9:960
  237. 2024-11-29 06:31:47.342746 92.10% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 8:960
  238. 2024-11-29 06:31:47.342746 92.10% [INFO] switch_channel.c:528 RECV DTMF 8:960
  239. 2024-11-29 06:31:48.042700 92.00% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF #:960
  240. span style="color: green; font-weight: bold;"> 2024-11-29 06:31:48.042700 92.00% [INFO] switch_channel.c:528 RECV DTMF #:960
  241. span style="color: goldenrod; font-weight: bold;"> 2024-11-29 06:31:48.042700 92.00% [DEBUG] switch_cpp.cpp:1465 [ASTPP] We Recieved A Pin Number : 472798
  242. 2024-11-29 06:31:48.042700 92.00% [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
  243. 2024-11-29 06:31:48.042700 92.00% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [validate_card_usage] Query :SELECT DATE_FORMAT('2024-11-29 06:31:48' , '%Y%m%d%H%i%s') AS expiry
  244. 2024-11-29 06:31:48.042700 92.00% [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
  245. 2024-11-29 06:31:48.042700 92.00% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
  246. 2024-11-29 06:31:50.862700 92.67% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/astpp-register.wav
  247. 2024-11-29 06:31:53.562726 92.87% [WARNING] switch_core_state_machine.c:684 cb9b034f-d23a-465e-91e9-c4d69b5f4f4b sofia/default/1001@78.47.101.152 Abandoned
  248. 2024-11-29 06:31:53.562726 92.87% [NOTICE] switch_core_state_machine.c:687 Hangup sofia/default/1001@78.47.101.152 [CS_NEW] [WRONG_CALL_STATE]
  249. 2024-11-29 06:31:53.562726 92.87% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1001@78.47.101.152) Running State Change CS_HANGUP (Cur 2 Tot 1678)
  250. 2024-11-29 06:31:53.562726 92.87% [DEBUG] switch_core_state_machine.c:844 (sofia/default/1001@78.47.101.152) Callstate Change DOWN -> HANGUP
  251. 2024-11-29 06:31:53.562726 92.87% [DEBUG] switch_core_state_machine.c:846 (sofia/default/1001@78.47.101.152) State HANGUP
  252. 2024-11-29 06:31:53.562726 92.87% [DEBUG] mod_sofia.c:469 Channel sofia/default/1001@78.47.101.152 hanging up, cause: WRONG_CALL_STATE
  253. 2024-11-29 06:31:53.562726 92.87% [DEBUG] switch_core_state_machine.c:59 sofia/default/1001@78.47.101.152 Standard HANGUP, cause: WRONG_CALL_STATE
  254. 2024-11-29 06:31:53.562726 92.87% [DEBUG] switch_core_state_machine.c:846 (sofia/default/1001@78.47.101.152) State HANGUP going to sleep
  255. 2024-11-29 06:31:53.562726 92.87% [DEBUG] switch_core_state_machine.c:616 (sofia/default/1001@78.47.101.152) State Change CS_HANGUP -> CS_REPORTING
  256. 2024-11-29 06:31:53.562726 92.87% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1001@78.47.101.152) Running State Change CS_REPORTING (Cur 2 Tot 1678)
  257. 2024-11-29 06:31:53.562726 92.87% [DEBUG] switch_core_state_machine.c:932 (sofia/default/1001@78.47.101.152) State REPORTING
  258. 2024-11-29 06:31:53.562726 92.87% [DEBUG] switch_core_state_machine.c:168 sofia/default/1001@78.47.101.152 Standard REPORTING, cause: WRONG_CALL_STATE
  259. 2024-11-29 06:31:53.562726 92.87% [DEBUG] switch_core_state_machine.c:932 (sofia/default/1001@78.47.101.152) State REPORTING going to sleep
  260. 2024-11-29 06:31:53.562726 92.87% [DEBUG] switch_core_state_machine.c:607 (sofia/default/1001@78.47.101.152) State Change CS_REPORTING -> CS_DESTROY
  261. 2024-11-29 06:31:53.562726 92.87% [DEBUG] switch_core_session.c:1744 Session 1678 (sofia/default/1001@78.47.101.152) Locked, Waiting on external entities
  262. 2024-11-29 06:31:53.562726 92.87% [NOTICE] switch_core_session.c:1762 Session 1678 (sofia/default/1001@78.47.101.152) Ended
  263. 2024-11-29 06:31:53.562726 92.87% [NOTICE] switch_core_session.c:1766 Close Channel sofia/default/1001@78.47.101.152 [CS_DESTROY]
  264. 2024-11-29 06:31:53.562726 92.87% [DEBUG] switch_core_state_machine.c:735 (sofia/default/1001@78.47.101.152) Running State Change CS_DESTROY (Cur 1 Tot 1678)
  265. 2024-11-29 06:31:53.562726 92.87% [DEBUG] switch_core_state_machine.c:745 (sofia/default/1001@78.47.101.152) State DESTROY
  266. 2024-11-29 06:31:53.562726 92.87% [DEBUG] mod_sofia.c:380 sofia/default/1001@78.47.101.152 SOFIA DESTROY
  267. 2024-11-29 06:31:53.562726 92.87% [DEBUG] switch_core_state_machine.c:175 sofia/default/1001@78.47.101.152 Standard DESTROY
  268. 2024-11-29 06:31:53.562726 92.87% [DEBUG] switch_core_state_machine.c:745 (sofia/default/1001@78.47.101.152) State DESTROY going to sleep
  269. 2024-11-29 06:31:55.862775 92.97% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [Accountcode : 4727985745]
  270. 2024-11-29 06:31:55.862775 92.97% [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
  271. 2024-11-29 06:31:55.862775 92.97% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
  272. 2024-11-29 06:31:57.182702 93.17% [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
  273. 2024-11-29 06:31:57.182702 93.17% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [Play Amount First Part] Query :845031
  274. 2024-11-29 06:31:57.182702 93.17% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [Play Amount Second Part] Query :54
  275. EXECUTE [depth=0] sofia/default/1187009497@astppdemo.astppbilling.org say(en number pronounced 845031)
  276. 2024-11-29 06:31:57.202697 93.17% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
  277. 2024-11-29 06:32:00.562710 93.00% [DEBUG] switch_ivr_play_say.c:2010 done playing file file_string://digits/8.wav!digits/hundred.wav!digits/40.wav!digits/5.wav!digits/thousand.wav!digits/30.wav!digits/1.wav
  278. 2024-11-29 06:32:00.562710 93.00% [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
  279. 2024-11-29 06:32:00.562710 93.00% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
  280. 2024-11-29 06:32:01.122760 93.03% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/astpp-point.wav
  281. EXECUTE [depth=0] sofia/default/1187009497@astppdemo.astppbilling.org say(en number pronounced 54)
  282. 2024-11-29 06:32:01.142720 93.03% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
  283. 2024-11-29 06:32:02.342701 92.47% [DEBUG] switch_ivr_play_say.c:2010 done playing file file_string://digits/50.wav!digits/4.wav
  284. 2024-11-29 06:32:02.342701 92.47% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [HP:access_number_call_flow[0:Go Direct Dial,1:Go IVR] : 0]
  285. 2024-11-29 06:32:02.342701 92.47% [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
  286. 2024-11-29 06:32:02.342701 92.47% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
  287. 2024-11-29 06:32:06.022838 90.70% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/astpp-phonenum.wav
  288. 2024-11-29 06:32:07.082797 90.67% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 1:960
  289. 2024-11-29 06:32:07.082797 90.67% [INFO] switch_channel.c:528 RECV DTMF 1:960
  290. 2024-11-29 06:32:07.442699 90.67% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 2:960
  291. 2024-11-29 06:32:07.442699 90.67% [INFO] switch_channel.c:528 RECV DTMF 2:960
  292. 2024-11-29 06:32:07.762739 90.67% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 4:960
  293. 2024-11-29 06:32:07.762739 90.67% [INFO] switch_channel.c:528 RECV DTMF 4:960
  294. 2024-11-29 06:32:08.042962 90.67% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 0:960
  295. 2024-11-29 06:32:08.042962 90.67% [INFO] switch_channel.c:528 RECV DTMF 0:960
  296. 2024-11-29 06:32:08.202745 90.67% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 6:960
  297. 2024-11-29 06:32:08.202745 90.67% [INFO] switch_channel.c:528 RECV DTMF 6:960
  298. 2024-11-29 06:32:08.382725 90.67% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 0:960
  299. 2024-11-29 06:32:08.382725 90.67% [INFO] switch_channel.c:528 RECV DTMF 0:960
  300. 2024-11-29 06:32:08.542705 90.67% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 6:960
  301. 2024-11-29 06:32:08.542705 90.67% [INFO] switch_channel.c:528 RECV DTMF 6:960
  302. 2024-11-29 06:32:08.702748 90.67% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 0:960
  303. 2024-11-29 06:32:08.702748 90.67% [INFO] switch_channel.c:528 RECV DTMF 0:960
  304. 2024-11-29 06:32:08.842791 90.67% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 6:960
  305. 2024-11-29 06:32:08.842791 90.67% [INFO] switch_channel.c:528 RECV DTMF 6:960
  306. 2024-11-29 06:32:09.082734 90.47% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 0:960
  307. 2024-11-29 06:32:09.082734 90.47% [INFO] switch_channel.c:528 RECV DTMF 0:960
  308. 2024-11-29 06:32:09.562713 90.47% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF #:960
  309. span style="color: green; font-weight: bold;"> 2024-11-29 06:32:09.562713 90.47% [INFO] switch_channel.c:528 RECV DTMF #:960
  310. span style="color: green; font-weight: bold;"> 2024-11-29 06:32:09.562713 90.47% [INFO] switch_cpp.cpp:1465 [ASTPP] [CHECK Destination] Dialed Destination Number :1240606060
  311. 2024-11-29 06:32:09.562713 90.47% [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 = '1240606060' OR number = '124060606' OR number = '12406060' OR number = '1240606' OR number = '124060' OR number = '12406' OR number = '1240' OR number = '124' OR number = '12' OR number = '1' OR number ='--') OR (number = '1240606060*' OR number = '124060606*' OR number = '12406060*' OR number = '1240606*' OR number = '124060*' OR number = '12406*' OR number = '1240*' OR number = '124*' OR number = '12*' OR number = '1*' OR number ='--') OR (number = '1187009497' OR number = '118700949' OR number = '11870094' OR number = '1187009' OR number = '118700' OR number = '11870' OR number = '1187' OR number = '118' OR number = '11' OR number = '1' OR number ='--') OR (number = '1187009497*' OR number = '118700949*' OR number = '11870094*' OR number = '1187009*' OR number = '118700*' OR number = '11870*' OR number = '1187*' OR number = '118*' OR number = '11*' OR number = '1*' OR number ='--')) AND status=0 order by LENGTH(number) DESC,lastchar DESC, modified_date DESC
  312. 2024-11-29 06:32:09.562713 90.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Call Barring Status : -1
  313. EXECUTE [depth=0] sofia/default/1187009497@astppdemo.astppbilling.org set(daily_call_credit_limit=0.00000)
  314. 2024-11-29 06:32:09.562713 90.47% [DEBUG] mod_dptools.c:1671 SET sofia/default/1187009497@astppdemo.astppbilling.org [daily_call_credit_limit]=[0.00000]
  315. EXECUTE [depth=0] sofia/default/1187009497@astppdemo.astppbilling.org export(daily_call_credit_limit=0.00000)
  316. 2024-11-29 06:32:09.562713 90.47% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [daily_call_credit_limit]=[0.00000]
  317. EXECUTE [depth=0] sofia/default/1187009497@astppdemo.astppbilling.org set(daily_call_used_limit=0.00000)
  318. 2024-11-29 06:32:09.562713 90.47% [DEBUG] mod_dptools.c:1671 SET sofia/default/1187009497@astppdemo.astppbilling.org [daily_call_used_limit]=[0.00000]
  319. EXECUTE [depth=0] sofia/default/1187009497@astppdemo.astppbilling.org export(daily_call_used_limit=0.00000)
  320. 2024-11-29 06:32:09.562713 90.47% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [daily_call_used_limit]=[0.00000]
  321. EXECUTE [depth=0] sofia/default/1187009497@astppdemo.astppbilling.org set(monthly_call_credit_limit=0.00000)
  322. 2024-11-29 06:32:09.562713 90.47% [DEBUG] mod_dptools.c:1671 SET sofia/default/1187009497@astppdemo.astppbilling.org [monthly_call_credit_limit]=[0.00000]
  323. EXECUTE [depth=0] sofia/default/1187009497@astppdemo.astppbilling.org export(monthly_call_credit_limit=0.00000)
  324. 2024-11-29 06:32:09.562713 90.47% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [monthly_call_credit_limit]=[0.00000]
  325. EXECUTE [depth=0] sofia/default/1187009497@astppdemo.astppbilling.org set(monthly_call_used_limit=0.00000)
  326. 2024-11-29 06:32:09.562713 90.47% [DEBUG] mod_dptools.c:1671 SET sofia/default/1187009497@astppdemo.astppbilling.org [monthly_call_used_limit]=[0.00000]
  327. EXECUTE [depth=0] sofia/default/1187009497@astppdemo.astppbilling.org export(monthly_call_used_limit=0.00000)
  328. 2024-11-29 06:32:09.582711 90.47% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [monthly_call_used_limit]=[0.00000]
  329. 2024-11-29 06:32:09.582711 90.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_PRICELIST_ROUTING_INFO] Query :select id,routing_prefix,pricelist_id_admin from pricelists WHERE (routing_prefix = '1240606060' OR routing_prefix = '124060606' OR routing_prefix = '12406060' OR routing_prefix = '1240606' OR routing_prefix = '124060' OR routing_prefix = '12406' OR routing_prefix = '1240' OR routing_prefix = '124' OR routing_prefix = '12' OR routing_prefix = '1' OR routing_prefix ='--') AND status = 0 and reseller_id = 0 limit 1
  330. 2024-11-29 06:32:09.582711 90.47% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Account Information ===================
  331. 2024-11-29 06:32:09.582711 90.47% [INFO] switch_cpp.cpp:1465 [ASTPP] User id : 2
  332. 2024-11-29 06:32:09.582711 90.47% [INFO] switch_cpp.cpp:1465 [ASTPP] Account code : 4727985745
  333. 2024-11-29 06:32:09.582711 90.47% [INFO] switch_cpp.cpp:1465 [ASTPP] Balance : 9999.9
  334. 2024-11-29 06:32:09.582711 90.47% [INFO] switch_cpp.cpp:1465 [ASTPP] Type : 0 [0:prepaid,1:postpaid]
  335. 2024-11-29 06:32:09.582711 90.47% [INFO] switch_cpp.cpp:1465 [ASTPP] Ratecard id : 1
  336. 2024-11-29 06:32:09.582711 90.47% [INFO] switch_cpp.cpp:1465 [ASTPP] CID Pool : 0
  337. 2024-11-29 06:32:09.582711 90.47% [INFO] switch_cpp.cpp:1465 [ASTPP] ========================================================
  338. 2024-11-29 06:32:09.582711 90.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CHECK_BLOCKED_PREFIX] Query :SELECT * FROM block_patterns WHERE (blocked_patterns = '^1240606060.*' OR blocked_patterns = '^124060606.*' OR blocked_patterns = '^12406060.*' OR blocked_patterns = '^1240606.*' OR blocked_patterns = '^124060.*' OR blocked_patterns = '^12406.*' OR blocked_patterns = '^1240.*' OR blocked_patterns = '^124.*' OR blocked_patterns = '^12.*' OR blocked_patterns = '^1.*' OR blocked_patterns ='--') AND accountid = 2 limit 1
  339. 2024-11-29 06:32:09.582711 90.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_PACKAGE_INFO] Query :SELECT *,P.id as package_id,P.product_id as product_id FROM packages_view as P inner join package_patterns as PKGPTR on P.product_id = PKGPTR.product_id WHERE P.is_terminated = 0 AND (patterns = '^1240606060.*' OR patterns = '^124060606.*' OR patterns = '^12406060.*' OR patterns = '^1240606.*' OR patterns = '^124060.*' OR patterns = '^12406.*' OR patterns = '^1240.*' OR patterns = '^124.*' OR patterns = '^12.*' OR patterns = '^1.*' OR patterns ='--') AND accountid = 2 ORDER BY LENGTH(PKGPTR.patterns) DESC
  340. 2024-11-29 06:32:09.582711 90.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 1 AND status = 0
  341. 2024-11-29 06:32:09.582711 90.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_RATES] call_direction :
  342. 2024-11-29 06:32:09.582711 90.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 1 AND status = 0
  343. 2024-11-29 06:32:09.582711 90.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_RATES] Query :SELECT * FROM routes WHERE (pattern = '^1240606060.*' OR pattern = '^124060606.*' OR pattern = '^12406060.*' OR pattern = '^1240606.*' OR pattern = '^124060.*' OR pattern = '^12406.*' OR pattern = '^1240.*' OR pattern = '^124.*' OR pattern = '^12.*' OR pattern = '^1.*' OR pattern ='--') AND (caller_id_pattern = '^1187009497.*' OR caller_id_pattern = '^118700949.*' OR caller_id_pattern = '^11870094.*' OR caller_id_pattern = '^1187009.*' OR caller_id_pattern = '^118700.*' OR caller_id_pattern = '^11870.*' OR caller_id_pattern = '^1187.*' OR caller_id_pattern = '^118.*' OR caller_id_pattern = '^11.*' OR caller_id_pattern = '^1.*' OR caller_id_pattern ='^.*') AND status = 0 AND effective_date <= UTC_TIMESTAMP() AND (pricelist_id = 1 OR accountid=2)  ORDER BY accountid DESC,LENGTH(pattern) DESC,LENGTH(caller_id_pattern) DESC,cost DESC,effective_date DESC LIMIT 1
  344. 2024-11-29 06:32:09.582711 90.47% [INFO] switch_cpp.cpp:1465 [ASTPP]  Call Direction :
  345. 2024-11-29 06:32:09.582711 90.47% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Rates Information ===================
  346. 2024-11-29 06:32:09.582711 90.47% [INFO] switch_cpp.cpp:1465 [ASTPP] ID : 1
  347. 2024-11-29 06:32:09.582711 90.47% [INFO] switch_cpp.cpp:1465 [ASTPP] Connectcost : 0.0000000000
  348. 2024-11-29 06:32:09.582711 90.47% [INFO] switch_cpp.cpp:1465 [ASTPP] Includedseconds : 0
  349. 2024-11-29 06:32:09.582711 90.47% [INFO] switch_cpp.cpp:1465 [ASTPP] Cost : 0.2000000000
  350. 2024-11-29 06:32:09.582711 90.47% [INFO] switch_cpp.cpp:1465 [ASTPP] Comment : USA
  351. 2024-11-29 06:32:09.582711 90.47% [INFO] switch_cpp.cpp:1465 [ASTPP] Country Id : 0
  352. 2024-11-29 06:32:09.582711 90.47% [INFO] switch_cpp.cpp:1465 [ASTPP] Accid : 2
  353. 2024-11-29 06:32:09.582711 90.47% [INFO] switch_cpp.cpp:1465 [ASTPP] Trunk ID: 0
  354. 2024-11-29 06:32:09.582711 90.47% [INFO] switch_cpp.cpp:1465 [ASTPP] Routing type:
  355. 2024-11-29 06:32:09.582711 90.47% [INFO] switch_cpp.cpp:1465 [ASTPP] ================================================================
  356. 2024-11-29 06:32:09.582711 90.47% [INFO] switch_cpp.cpp:1465 [ASTPP] [FIND_MAXLENGTH] Your9999.9 balance Accountid 2 !!!
  357. 2024-11-29 06:32:09.582711 90.47% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [FIND_MAXLENGTH] Limiting Call To Config Max Length 100 mins!
  358. 2024-11-29 06:32:09.582711 90.47% [NOTICE] switch_cpp.cpp:1465 [ASTPP] 100 Minutes
  359. 2024-11-29 06:32:09.582711 90.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [SAY_TIMELIMIT] MINUTES 100
  360. 2024-11-29 06:32:09.582711 90.47% [DEBUG] switch_core_file.c:444 File /usr/local/freeswitch/sounds/en/us/callie/astpp-this-call-will-last.wav sample rate 16000 doesn't match requested rate 8000
  361. 2024-11-29 06:32:09.582711 90.47% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
  362. 2024-11-29 06:32:10.762717 90.27% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/astpp-this-call-will-last.wav
  363. EXECUTE [depth=0] sofia/default/1187009497@astppdemo.astppbilling.org say(en number pronounced 100)
  364. 2024-11-29 06:32:10.782700 90.27% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
  365. 2024-11-29 06:32:11.942721 90.30% [DEBUG] switch_ivr_play_say.c:2010 done playing file file_string://digits/1.wav!digits/hundred.wav
  366. 2024-11-29 06:32:11.942721 90.30% [DEBUG] switch_core_file.c:444 File /usr/local/freeswitch/sounds/en/us/callie/astpp-minutes.wav sample rate 16000 doesn't match requested rate 8000
  367. 2024-11-29 06:32:11.942721 90.30% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
  368. 2024-11-29 06:32:12.562710 90.17% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/astpp-minutes.wav
  369. 2024-11-29 06:32:12.562710 90.17% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_CARRIER_RATES] Query Rate Carrier Id :0
  370. 2024-11-29 06:32:12.562710 90.17% [ERR] mod_lua.cpp:202 /usr/local/freeswitch/scripts/astpp/lib/astpp.functions.lua:1755: attempt to index global 'callerid_array' (a nil value)
  371. stack traceback:
  372.         /usr/local/freeswitch/scripts/astpp/lib/astpp.functions.lua:1755: in function 'get_carrier_rates'
  373.         ...switch/scripts/astpp/lib/astpp.callingcard.functions.lua:373: in function 'dialout'
  374.         ...switch/scripts/astpp/lib/astpp.callingcard.functions.lua:1330: in function 'process_destination'
  375.         /usr/local/freeswitch/scripts/astpp-callingcards.lua:122: in main chunk
  376. 2024-11-29 06:32:12.562710 90.17% [DEBUG] switch_cpp.cpp:1209 sofia/default/1187009497@astppdemo.astppbilling.org destroy/unlink session from object
  377. 2024-11-29 06:32:12.562710 90.17% [NOTICE] switch_core_state_machine.c:382 sofia/default/1187009497@astppdemo.astppbilling.org has executed the last dialplan instruction, hanging up.
  378. 2024-11-29 06:32:12.562710 90.17% [NOTICE] switch_core_state_machine.c:384 Hangup sofia/default/1187009497@astppdemo.astppbilling.org [CS_EXECUTE] [NORMAL_CLEARING]
  379. 2024-11-29 06:32:12.562710 90.17% [DEBUG] switch_core_state_machine.c:647 (sofia/default/1187009497@astppdemo.astppbilling.org) State EXECUTE going to sleep
  380. 2024-11-29 06:32:12.562710 90.17% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1187009497@astppdemo.astppbilling.org) Running State Change CS_HANGUP (Cur 1 Tot 1678)
  381. 2024-11-29 06:32:12.562710 90.17% [DEBUG] switch_core_state_machine.c:844 (sofia/default/1187009497@astppdemo.astppbilling.org) Callstate Change ACTIVE -> HANGUP
  382. 2024-11-29 06:32:12.562710 90.17% [DEBUG] switch_core_state_machine.c:846 (sofia/default/1187009497@astppdemo.astppbilling.org) State HANGUP
  383. 2024-11-29 06:32:12.562710 90.17% [DEBUG] mod_sofia.c:469 Channel sofia/default/1187009497@astppdemo.astppbilling.org hanging up, cause: NORMAL_CLEARING
  384. 2024-11-29 06:32:12.582694 90.17% [DEBUG] mod_sofia.c:523 Sending BYE to sofia/default/1187009497@astppdemo.astppbilling.org
  385. 2024-11-29 06:32:12.582694 90.17% [DEBUG] switch_core_state_machine.c:59 sofia/default/1187009497@astppdemo.astppbilling.org Standard HANGUP, cause: NORMAL_CLEARING
  386. 2024-11-29 06:32:12.582694 90.17% [DEBUG] switch_core_state_machine.c:846 (sofia/default/1187009497@astppdemo.astppbilling.org) State HANGUP going to sleep
  387. 2024-11-29 06:32:12.582694 90.17% [DEBUG] switch_core_state_machine.c:616 (sofia/default/1187009497@astppdemo.astppbilling.org) State Change CS_HANGUP -> CS_REPORTING
  388. 2024-11-29 06:32:12.582694 90.17% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1187009497@astppdemo.astppbilling.org) Running State Change CS_REPORTING (Cur 1 Tot 1678)
  389. 2024-11-29 06:32:12.582694 90.17% [DEBUG] switch_core_state_machine.c:932 (sofia/default/1187009497@astppdemo.astppbilling.org) State REPORTING
  390. 2024-11-29 06:32:12.582694 90.17% [INFO] mod_json_cdr.c:272 Process [2992c2f2-dfcd-4b04-b9e0-cbc1583cccee.cdr.json]
  391. 2024-11-29 06:32:12.602695 90.17% [DEBUG] switch_core_state_machine.c:168 sofia/default/1187009497@astppdemo.astppbilling.org Standard REPORTING, cause: NORMAL_CLEARING
  392. 2024-11-29 06:32:12.602695 90.17% [DEBUG] switch_core_state_machine.c:932 (sofia/default/1187009497@astppdemo.astppbilling.org) State REPORTING going to sleep
  393. 2024-11-29 06:32:12.602695 90.17% [DEBUG] switch_core_state_machine.c:607 (sofia/default/1187009497@astppdemo.astppbilling.org) State Change CS_REPORTING -> CS_DESTROY
  394. 2024-11-29 06:32:12.602695 90.17% [DEBUG] switch_core_session.c:1744 Session 1677 (sofia/default/1187009497@astppdemo.astppbilling.org) Locked, Waiting on external entities
  395. 2024-11-29 06:32:12.602695 90.17% [NOTICE] switch_core_session.c:1762 Session 1677 (sofia/default/1187009497@astppdemo.astppbilling.org) Ended
  396. 2024-11-29 06:32:12.602695 90.17% [NOTICE] switch_core_session.c:1766 Close Channel sofia/default/1187009497@astppdemo.astppbilling.org [CS_DESTROY]
  397. 2024-11-29 06:32:12.602695 90.17% [DEBUG] switch_core_state_machine.c:735 (sofia/default/1187009497@astppdemo.astppbilling.org) Running State Change CS_DESTROY (Cur 0 Tot 1678)
  398. 2024-11-29 06:32:12.602695 90.17% [DEBUG] switch_core_state_machine.c:745 (sofia/default/1187009497@astppdemo.astppbilling.org) State DESTROY
  399. 2024-11-29 06:32:12.602695 90.17% [DEBUG] mod_sofia.c:380 sofia/default/1187009497@astppdemo.astppbilling.org SOFIA DESTROY
  400. 2024-11-29 06:32:12.602695 90.17% [DEBUG] switch_core_state_machine.c:175 sofia/default/1187009497@astppdemo.astppbilling.org Standard DESTROY
  401. 2024-11-29 06:32:12.602695 90.17% [DEBUG] switch_core_state_machine.c:745 (sofia/default/1187009497@astppdemo.astppbilling.org) State DESTROY going to sleep
  402. 2024-11-29 06:32:30.922692 85.90% [WARNING] sofia_reg.c:1842 SIP auth challenge (REGISTER) on sofia profile 'default' for [9378@78.47.101.152] from ip 94.23.161.138
  403. 2024-11-29 06:32:30.962687 85.90% [WARNING] sofia_reg.c:3210 Can't find user [9378@78.47.101.152] from 94.23.161.138
  404. You must define a domain called '78.47.101.152' in your directory and add a user with the id="9378" attribute
  405. and you must configure your device to use the proper domain in its authentication credentials.
  406. 2024-11-29 06:32:30.962687 85.90% [WARNING] sofia_reg.c:1787 SIP auth failure (REGISTER) on sofia profile 'default' for [9378@78.47.101.152] from ip 94.23.161.138
  407. freeswitch@GuiOsip1ClusterQa-Alpesh>

Reply to "error in fs_cli log during Call by Calling card"