From CC with ID, 3 Years ago, written in Lua.
- view diff
Embed
  1. 2021-02-17 10:06:53.104254 [NOTICE] switch_channel.c:1118 New Channel sofia/default/3855458128@65.0.179.216 [81ad0253-bd09-4431-b9be-902fc100875e]
  2. 2021-02-17 10:06:53.104254 [DEBUG] switch_core_state_machine.c:585 (sofia/default/3855458128@65.0.179.216) Running State Change CS_NEW (Cur 2 Tot 82326)
  3. 2021-02-17 10:06:53.104254 [DEBUG] sofia.c:10280 sofia/default/3855458128@65.0.179.216 receiving invite from 117.247.91.162:4585 version: 1.10.5 -release-17-25569c1631 64bit
  4. 2021-02-17 10:06:53.104254 [DEBUG] sofia.c:10374 verifying acl "default" for ip/port 117.247.91.162:0.
  5. 2021-02-17 10:06:53.104254 [DEBUG] sofia.c:2434 detaching session 81ad0253-bd09-4431-b9be-902fc100875e
  6. 2021-02-17 10:06:53.104254 [WARNING] sofia_reg.c:1794 SIP auth challenge (INVITE) on sofia profile 'default' for [180001111@65.0.179.216] from ip 117.247.91.162
  7. 2021-02-17 10:06:53.104254 [DEBUG] switch_core_state_machine.c:604 (sofia/default/3855458128@65.0.179.216) State NEW
  8. 2021-02-17 10:06:53.129873 [DEBUG] sofia.c:2544 Re-attaching to session 81ad0253-bd09-4431-b9be-902fc100875e
  9. 2021-02-17 10:06:53.129873 [DEBUG] sofia.c:10280 sofia/default/3855458128@65.0.179.216 receiving invite from 117.247.91.162:4585 version: 1.10.5 -release-17-25569c1631 64bit
  10. 2021-02-17 10:06:53.129873 [DEBUG] sofia.c:10374 verifying acl "default" for ip/port 117.247.91.162:0.
  11. 2021-02-17 10:06:53.164227 [DEBUG] sofia.c:7326 Channel sofia/default/3855458128@65.0.179.216 entering state [received][100]
  12. 2021-02-17 10:06:53.164227 [DEBUG] sofia.c:7336 Remote SDP:
  13. v=0
  14. o=3855458128 3883 1107 IN IP4 117.247.91.162
  15. s=Talk
  16. c=IN IP4 117.247.91.162
  17. t=0 0
  18. m=audio 7078 RTP/AVP 124 111 110 0 8 101
  19. a=rtpmap:124 opus/48000
  20. a=fmtp:124 useinbandfec=1; usedtx=1
  21. a=rtpmap:111 speex/16000
  22. a=fmtp:111 vbr=on
  23. a=rtpmap:110 speex/8000
  24. a=fmtp:110 vbr=on
  25. a=rtpmap:101 telephone-event/8000
  26. a=fmtp:101 0-11
  27. m=video 9078 RTP/AVP 103 99
  28. a=rtpmap:103 VP8/90000
  29. a=rtpmap:99 MP4V-ES/90000
  30. a=fmtp:99 profile-level-id=3
  31.  
  32. 2021-02-17 10:06:53.164227 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [opus:124:48000:20:0:1]/[PCMA:8:8000:20:64000:1]
  33. 2021-02-17 10:06:53.164227 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [opus:124:48000:20:0:1]/[PCMU:0:8000:20:64000:1]
  34. 2021-02-17 10:06:53.164227 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [speex:111:16000:20:0:1]/[PCMA:8:8000:20:64000:1]
  35. 2021-02-17 10:06:53.164227 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [speex:111:16000:20:0:1]/[PCMU:0:8000:20:64000:1]
  36. 2021-02-17 10:06:53.164227 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [speex:110:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
  37. 2021-02-17 10:06:53.164227 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [speex:110:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
  38. 2021-02-17 10:06:53.164227 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  39. 2021-02-17 10:06:53.164227 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  40. 2021-02-17 10:06:53.164227 [DEBUG] switch_core_media.c:5649 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  41. 2021-02-17 10:06:53.164227 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  42. 2021-02-17 10:06:53.164227 [DEBUG] switch_core_media.c:5649 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  43. 2021-02-17 10:06:53.164227 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  44. 2021-02-17 10:06:53.164227 [DEBUG] switch_core_media.c:5510 Set telephone-event payload to 101@8000
  45. 2021-02-17 10:06:53.164227 [DEBUG] switch_core_media.c:3839 Set Codec sofia/default/3855458128@65.0.179.216 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
  46. 2021-02-17 10:06:53.164227 [DEBUG] switch_core_codec.c:111 sofia/default/3855458128@65.0.179.216 Original read codec set to PCMU:0
  47. 2021-02-17 10:06:53.164227 [DEBUG] switch_core_media.c:5853 Set telephone-event payload to 101@8000
  48. 2021-02-17 10:06:53.164227 [DEBUG] switch_core_media.c:5911 sofia/default/3855458128@65.0.179.216 Set 2833 dtmf send payload to 101 recv payload to 101
  49. 2021-02-17 10:06:53.164227 [DEBUG] switch_core_media.c:6239 No matches with FTMP, fallback to ignoring FMTP
  50. 2021-02-17 10:06:53.164227 [DEBUG] switch_core_media.c:6247 No matches with inherit_codec, fallback to ignoring PT
  51. 2021-02-17 10:06:53.164227 [DEBUG] sofia.c:7760 (sofia/default/3855458128@65.0.179.216) State Change CS_NEW -> CS_INIT
  52. 2021-02-17 10:06:53.164227 [DEBUG] switch_core_state_machine.c:585 (sofia/default/3855458128@65.0.179.216) Running State Change CS_INIT (Cur 2 Tot 82326)
  53. 2021-02-17 10:06:53.164227 [DEBUG] switch_core_state_machine.c:628 (sofia/default/3855458128@65.0.179.216) State INIT
  54. 2021-02-17 10:06:53.164227 [DEBUG] mod_sofia.c:93 sofia/default/3855458128@65.0.179.216 SOFIA INIT
  55. 2021-02-17 10:06:53.164227 [DEBUG] switch_core_state_machine.c:40 sofia/default/3855458128@65.0.179.216 Standard INIT
  56. 2021-02-17 10:06:53.164227 [DEBUG] switch_core_state_machine.c:48 (sofia/default/3855458128@65.0.179.216) State Change CS_INIT -> CS_ROUTING
  57. 2021-02-17 10:06:53.164227 [DEBUG] switch_core_state_machine.c:628 (sofia/default/3855458128@65.0.179.216) State INIT going to sleep
  58. 2021-02-17 10:06:53.164227 [DEBUG] switch_core_state_machine.c:585 (sofia/default/3855458128@65.0.179.216) Running State Change CS_ROUTING (Cur 2 Tot 82326)
  59. 2021-02-17 10:06:53.164227 [DEBUG] switch_channel.c:2332 (sofia/default/3855458128@65.0.179.216) Callstate Change DOWN -> RINGING
  60. 2021-02-17 10:06:53.164227 [DEBUG] switch_core_state_machine.c:644 (sofia/default/3855458128@65.0.179.216) State ROUTING
  61. 2021-02-17 10:06:53.164227 [DEBUG] mod_sofia.c:154 sofia/default/3855458128@65.0.179.216 SOFIA ROUTING
  62. 2021-02-17 10:06:53.164227 [DEBUG] switch_core_state_machine.c:236 sofia/default/3855458128@65.0.179.216 Standard ROUTING
  63. 2021-02-17 10:06:53.164227 [INFO] mod_dialplan_xml.c:637 Processing 3855458128 <3855458128>->180001111 in context default
  64. 2021-02-17 10:06:53.244229 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes')
  65. 2021-02-17 10:06:53.244229 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
  66. 2021-02-17 10:06:53.264226 [INFO] switch_cpp.cpp:1447 [ASTPP] [Dialplan] Dialed number : 180001111
  67. 2021-02-17 10:06:53.264226 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [DOAUTHORIZATION] Query :SELECT access_number FROM accessnumber WHERE access_number = '180001111' AND status=0 limit 1
  68. 2021-02-17 10:06:53.264226 [DEBUG] switch_cpp.cpp:1447 [ASTPP] Generated XML:
  69. <?xml version="1.0" encoding="UTF-8" standalone="no"?>
  70. <document type="freeswitch/xml">
  71. <section name="dialplan" description="ASTPP Dialplan">
  72. <context name="default">
  73. <extension name="180001111">
  74. <condition field="destination_number" expression="180001111">
  75. <action application="log" data="INFO ASTPP - Calling Card Call"/>
  76. <action application="answer"/>
  77. <action application="sleep" data="2000"/>
  78. <action application="lua" data="astpp-callingcards.lua"/>
  79. </condition>
  80. </extension>
  81. </context>
  82. </section>
  83. </document>
  84. Dialplan: sofia/default/3855458128@65.0.179.216 parsing [default->180001111] continue=false
  85. Dialplan: sofia/default/3855458128@65.0.179.216 Regex (PASS) [180001111] destination_number(180001111) =~ /180001111/ break=on-false
  86. Dialplan: sofia/default/3855458128@65.0.179.216 Action log(INFO ASTPP - Calling Card Call)
  87. Dialplan: sofia/default/3855458128@65.0.179.216 Action answer()
  88. Dialplan: sofia/default/3855458128@65.0.179.216 Action sleep(2000)
  89. Dialplan: sofia/default/3855458128@65.0.179.216 Action lua(astpp-callingcards.lua)
  90. 2021-02-17 10:06:53.264226 [DEBUG] switch_core_state_machine.c:287 (sofia/default/3855458128@65.0.179.216) State Change CS_ROUTING -> CS_EXECUTE
  91. 2021-02-17 10:06:53.264226 [DEBUG] switch_core_state_machine.c:644 (sofia/default/3855458128@65.0.179.216) State ROUTING going to sleep
  92. 2021-02-17 10:06:53.264226 [DEBUG] switch_core_state_machine.c:585 (sofia/default/3855458128@65.0.179.216) Running State Change CS_EXECUTE (Cur 2 Tot 82326)
  93. 2021-02-17 10:06:53.264226 [DEBUG] switch_core_state_machine.c:651 (sofia/default/3855458128@65.0.179.216) State EXECUTE
  94. 2021-02-17 10:06:53.264226 [DEBUG] mod_sofia.c:209 sofia/default/3855458128@65.0.179.216 SOFIA EXECUTE
  95. 2021-02-17 10:06:53.264226 [DEBUG] switch_core_state_machine.c:329 sofia/default/3855458128@65.0.179.216 Standard EXECUTE
  96. EXECUTE [depth=0] sofia/default/3855458128@65.0.179.216 log(INFO ASTPP - Calling Card Call)
  97. 2021-02-17 10:06:53.264226 [INFO] mod_dptools.c:1866 ASTPP - Calling Card Call
  98. EXECUTE [depth=0] sofia/default/3855458128@65.0.179.216 answer()
  99. 2021-02-17 10:06:53.264226 [DEBUG] switch_core_media.c:8663 AUDIO RTP [sofia/default/3855458128@65.0.179.216] 172.31.14.168 port 27924 -> 117.247.91.162 port 7078 codec: 0 ms: 20
  100. 2021-02-17 10:06:53.264226 [DEBUG] switch_rtp.c:4450 Starting timer [soft] 160 bytes per 20ms
  101. 2021-02-17 10:06:53.264226 [DEBUG] switch_core_media.c:8977 sofia/default/3855458128@65.0.179.216 Set 2833 dtmf send payload to 101
  102. 2021-02-17 10:06:53.264226 [DEBUG] switch_core_media.c:8984 sofia/default/3855458128@65.0.179.216 Set 2833 dtmf receive payload to 101
  103. 2021-02-17 10:06:53.264226 [DEBUG] switch_core_media.c:9007 sofia/default/3855458128@65.0.179.216 Set rtp dtmf delay to 40
  104. 2021-02-17 10:06:53.264226 [DEBUG] mod_sofia.c:898 Local SDP sofia/default/3855458128@65.0.179.216:
  105. v=0
  106. o=FreeSWITCH 1613528489 1613528490 IN IP4 65.0.179.216
  107. s=FreeSWITCH
  108. c=IN IP4 65.0.179.216
  109. t=0 0
  110. m=audio 27924 RTP/AVP 0 101
  111. a=rtpmap:0 PCMU/8000
  112. a=rtpmap:101 telephone-event/8000
  113. a=fmtp:101 0-16
  114. a=ptime:20
  115. a=sendrecv
  116. m=video 0 RTP/AVP 19
  117.  
  118. 2021-02-17 10:06:53.264226 [NOTICE] mod_dptools.c:1406 Channel [sofia/default/3855458128@65.0.179.216] has been answered
  119. 2021-02-17 10:06:53.264226 [DEBUG] switch_channel.c:3865 (sofia/default/3855458128@65.0.179.216) Callstate Change RINGING -> ACTIVE
  120. 2021-02-17 10:06:53.264226 [DEBUG] sofia.c:7326 Channel sofia/default/3855458128@65.0.179.216 entering state [completed][200]
  121. EXECUTE [depth=0] sofia/default/3855458128@65.0.179.216 sleep(2000)
  122. 2021-02-17 10:06:53.284252 [WARNING] switch_core_state_machine.c:688 75353a84-fe7b-49e3-9cfd-a088663d7df8 sofia/default/38013801@65.0.179.216 Abandoned
  123. 2021-02-17 10:06:53.284252 [NOTICE] switch_core_state_machine.c:691 Hangup sofia/default/38013801@65.0.179.216 [CS_NEW] [WRONG_CALL_STATE]
  124. 2021-02-17 10:06:53.284252 [DEBUG] switch_core_state_machine.c:585 (sofia/default/38013801@65.0.179.216) Running State Change CS_HANGUP (Cur 2 Tot 82326)
  125. 2021-02-17 10:06:53.284252 [DEBUG] switch_core_state_machine.c:848 (sofia/default/38013801@65.0.179.216) Callstate Change DOWN -> HANGUP
  126. 2021-02-17 10:06:53.284252 [DEBUG] switch_core_state_machine.c:850 (sofia/default/38013801@65.0.179.216) State HANGUP
  127. 2021-02-17 10:06:53.284252 [DEBUG] mod_sofia.c:453 Channel sofia/default/38013801@65.0.179.216 hanging up, cause: WRONG_CALL_STATE
  128. 2021-02-17 10:06:53.284252 [DEBUG] switch_core_state_machine.c:60 sofia/default/38013801@65.0.179.216 Standard HANGUP, cause: WRONG_CALL_STATE
  129. 2021-02-17 10:06:53.284252 [DEBUG] switch_core_state_machine.c:850 (sofia/default/38013801@65.0.179.216) State HANGUP going to sleep
  130. 2021-02-17 10:06:53.284252 [DEBUG] switch_core_state_machine.c:620 (sofia/default/38013801@65.0.179.216) State Change CS_HANGUP -> CS_REPORTING
  131. 2021-02-17 10:06:53.284252 [DEBUG] switch_core_state_machine.c:585 (sofia/default/38013801@65.0.179.216) Running State Change CS_REPORTING (Cur 2 Tot 82326)
  132. 2021-02-17 10:06:53.284252 [DEBUG] switch_core_state_machine.c:936 (sofia/default/38013801@65.0.179.216) State REPORTING
  133. 2021-02-17 10:06:53.284252 [DEBUG] switch_core_state_machine.c:174 sofia/default/38013801@65.0.179.216 Standard REPORTING, cause: WRONG_CALL_STATE
  134. 2021-02-17 10:06:53.284252 [DEBUG] switch_core_state_machine.c:936 (sofia/default/38013801@65.0.179.216) State REPORTING going to sleep
  135. 2021-02-17 10:06:53.284252 [DEBUG] switch_core_state_machine.c:611 (sofia/default/38013801@65.0.179.216) State Change CS_REPORTING -> CS_DESTROY
  136. 2021-02-17 10:06:53.284252 [DEBUG] switch_core_session.c:1726 Session 82325 (sofia/default/38013801@65.0.179.216) Locked, Waiting on external entities
  137. 2021-02-17 10:06:53.284252 [NOTICE] switch_core_session.c:1744 Session 82325 (sofia/default/38013801@65.0.179.216) Ended
  138. 2021-02-17 10:06:53.284252 [NOTICE] switch_core_session.c:1748 Close Channel sofia/default/38013801@65.0.179.216 [CS_DESTROY]
  139. 2021-02-17 10:06:53.284252 [DEBUG] switch_core_state_machine.c:739 (sofia/default/38013801@65.0.179.216) Running State Change CS_DESTROY (Cur 1 Tot 82326)
  140. 2021-02-17 10:06:53.284252 [DEBUG] switch_core_state_machine.c:749 (sofia/default/38013801@65.0.179.216) State DESTROY
  141. 2021-02-17 10:06:53.284252 [DEBUG] mod_sofia.c:364 sofia/default/38013801@65.0.179.216 SOFIA DESTROY
  142. 2021-02-17 10:06:53.284252 [DEBUG] switch_core_state_machine.c:181 sofia/default/38013801@65.0.179.216 Standard DESTROY
  143. 2021-02-17 10:06:53.284252 [DEBUG] switch_core_state_machine.c:749 (sofia/default/38013801@65.0.179.216) State DESTROY going to sleep
  144. 2021-02-17 10:06:53.304230 [DEBUG] sofia.c:7326 Channel sofia/default/3855458128@65.0.179.216 entering state [ready][200]
  145. 2021-02-17 10:06:53.424255 [DEBUG] switch_rtp.c:7759 Correct audio ip/port confirmed.
  146. EXECUTE [depth=0] sofia/default/3855458128@65.0.179.216 lua(astpp-callingcards.lua)
  147. 2021-02-17 10:06:55.264226 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes')
  148. 2021-02-17 10:06:55.264226 [NOTICE] switch_cpp.cpp:1447 [ASTPP] SECTION
  149. 2021-02-17 10:06:55.264226 [DEBUG] switch_core_file.c:405 File /usr/share/freeswitch/sounds/en/us/callie/astpp-welcome.wav sample rate 16000 doesn't match requested rate 8000
  150. 2021-02-17 10:06:55.264226 [DEBUG] switch_ivr_play_say.c:1488 Codec Activated L16@8000hz 1 channels 20ms
  151. 2021-02-17 10:06:57.064253 [DEBUG] switch_ivr_play_say.c:1933 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-welcome.wav
  152. 2021-02-17 10:06:57.064253 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [CHECK_DID] Query :SELECT * FROM ani_map WHERE number = 3855458128
  153. 2021-02-17 10:06:57.064253 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [DOAUTHORIZATION] Query :SELECT *,(select currencyrate from currency where id=currency_id) as currencyrate FROM accounts WHERE (number = "14" OR id="14") AND status=0 AND deleted=0 limit 1
  154. 2021-02-17 10:06:57.064253 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [validate_card_usage] Query :SELECT DATE_FORMAT('2031-02-14 09:49:05' , '%Y%m%d%H%i%s') AS expiry
  155. 2021-02-17 10:06:57.064253 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [validate_card_usage] Query :SELECT DATE_FORMAT('2021-02-17 10:06:57' , '%Y%m%d%H%i%s') AS expiry
  156. 2021-02-17 10:06:57.064253 [NOTICE] switch_cpp.cpp:1447 [ASTPP] [Accountcode : 1594415095]
  157. 2021-02-17 10:06:57.064253 [DEBUG] switch_core_file.c:405 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
  158. 2021-02-17 10:06:57.064253 [DEBUG] switch_ivr_play_say.c:1488 Codec Activated L16@8000hz 1 channels 20ms
  159. 2021-02-17 10:06:58.167683 [WARNING] sofia_reg.c:1794 SIP auth challenge (REGISTER) on sofia profile 'default' for [1630@65.0.179.216] from ip 185.217.71.236
  160. 2021-02-17 10:06:58.384259 [DEBUG] switch_ivr_play_say.c:1933 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-this-card-has-a-balance-of.wav
  161. 2021-02-17 10:06:58.384259 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [Play Amount First Part] Query :3
  162. 2021-02-17 10:06:58.384259 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [Play Amount Second Part] Query :88
  163. EXECUTE [depth=0] sofia/default/3855458128@65.0.179.216 say(en number pronounced 3)
  164. 2021-02-17 10:06:58.384259 [WARNING] sofia_reg.c:2930 Can't find user [1630@172.31.14.168] from 185.217.71.236
  165. You must define a domain called '172.31.14.168' in your directory and add a user with the id="1630" attribute
  166. and you must configure your device to use the proper domain in its authentication credentials.
  167. 2021-02-17 10:06:58.384259 [WARNING] sofia_reg.c:1739 SIP auth failure (REGISTER) on sofia profile 'default' for [1630@65.0.179.216] from ip 185.217.71.236
  168. 2021-02-17 10:06:58.384259 [DEBUG] switch_ivr_play_say.c:1488 Codec Activated L16@8000hz 1 channels 20ms
  169. 2021-02-17 10:06:59.044252 [DEBUG] switch_ivr_play_say.c:1933 done playing file file_string://digits/3.wav
  170. 2021-02-17 10:06:59.044252 [DEBUG] switch_core_file.c:405 File /usr/share/freeswitch/sounds/en/us/callie/astpp-point.wav sample rate 16000 doesn't match requested rate 8000
  171. 2021-02-17 10:06:59.044252 [DEBUG] switch_ivr_play_say.c:1488 Codec Activated L16@8000hz 1 channels 20ms
  172. 2021-02-17 10:06:59.604253 [DEBUG] switch_ivr_play_say.c:1933 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-point.wav
  173. EXECUTE [depth=0] sofia/default/3855458128@65.0.179.216 say(en number pronounced 88)
  174. 2021-02-17 10:06:59.604253 [DEBUG] switch_ivr_play_say.c:1488 Codec Activated L16@8000hz 1 channels 20ms
  175. 2021-02-17 10:07:00.624231 [DEBUG] switch_ivr_play_say.c:1933 done playing file file_string://digits/80.wav!digits/8.wav
  176. 2021-02-17 10:07:00.624231 [DEBUG] switch_core_file.c:405 File /usr/share/freeswitch/sounds/en/us/callie/astpp-phonenum.wav sample rate 16000 doesn't match requested rate 8000
  177. 2021-02-17 10:07:00.624231 [DEBUG] switch_ivr_play_say.c:1488 Codec Activated L16@8000hz 1 channels 20ms
  178. 2021-02-17 10:07:04.324252 [DEBUG] switch_ivr_play_say.c:1933 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-phonenum.wav
  179. freeswitch@ip-172-31-14-168>
  180. freeswitch@ip-172-31-14-168>
  181. freeswitch@ip-172-31-14-168>
  182. freeswitch@ip-172-31-14-168>
  183. 2021-02-17 10:07:19.355314 [DEBUG] switch_core_file.c:405 File /usr/share/freeswitch/sounds/en/us/callie/astpp-badphone.wav sample rate 16000 doesn't match requested rate 8000
  184. 2021-02-17 10:07:19.355314 [DEBUG] switch_ivr_play_say.c:1488 Codec Activated L16@8000hz 1 channels 20ms
  185. 2021-02-17 10:07:19.724232 [NOTICE] switch_channel.c:1118 New Channel sofia/default/38013801@65.0.179.216 [0d1ed6a3-ff94-4904-8d93-ad937bc7d8a7]
  186. 2021-02-17 10:07:19.724232 [DEBUG] switch_core_state_machine.c:585 (sofia/default/38013801@65.0.179.216) Running State Change CS_NEW (Cur 2 Tot 82327)
  187. 2021-02-17 10:07:19.724232 [DEBUG] sofia.c:10280 sofia/default/38013801@65.0.179.216 receiving invite from 23.146.241.14:52129 version: 1.10.5 -release-17-25569c1631 64bit
  188. 2021-02-17 10:07:19.724232 [DEBUG] sofia.c:10374 verifying acl "default" for ip/port 23.146.241.14:0.
  189. 2021-02-17 10:07:19.724232 [DEBUG] sofia.c:2434 detaching session 0d1ed6a3-ff94-4904-8d93-ad937bc7d8a7
  190. 2021-02-17 10:07:19.724232 [WARNING] sofia_reg.c:1794 SIP auth challenge (INVITE) on sofia profile 'default' for [9011442037694911@65.0.179.216] from ip 23.146.241.14
  191. 2021-02-17 10:07:19.724232 [DEBUG] switch_core_state_machine.c:604 (sofia/default/38013801@65.0.179.216) State NEW
  192. 2021-02-17 10:07:20.784251 [DEBUG] switch_ivr_play_say.c:1933 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-badphone.wav
  193. 2021-02-17 10:07:20.784251 [DEBUG] switch_core_file.c:405 File /usr/share/freeswitch/sounds/en/us/callie/astpp-phonenum.wav sample rate 16000 doesn't match requested rate 8000
  194. 2021-02-17 10:07:20.784251 [DEBUG] switch_ivr_play_say.c:1488 Codec Activated L16@8000hz 1 channels 20ms
  195. 2021-02-17 10:07:24.484245 [DEBUG] switch_ivr_play_say.c:1933 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-phonenum.wav
  196. 2021-02-17 10:07:29.244249 [NOTICE] sofia.c:1089 Hangup sofia/default/3855458128@65.0.179.216 [CS_EXECUTE] [NORMAL_CLEARING]
  197. 2021-02-17 10:07:29.244249 [INFO] switch_cpp.cpp:1447 [ASTPP] [CHECK_destination] Dialed destination number :
  198. 2021-02-17 10:07:29.244249 [INFO] switch_cpp.cpp:1447 [ASTPP] =============== Account Information ===================
  199. 2021-02-17 10:07:29.244249 [INFO] switch_cpp.cpp:1447 [ASTPP] User id : 14
  200. 2021-02-17 10:07:29.244249 [INFO] switch_cpp.cpp:1447 [ASTPP] Account code : 1594415095
  201. 2021-02-17 10:07:29.244249 [INFO] switch_cpp.cpp:1447 [ASTPP] Balance : 3.8833
  202. 2021-02-17 10:07:29.244249 [INFO] switch_cpp.cpp:1447 [ASTPP] Type : 0 [0:prepaid,1:postpaid]
  203. 2021-02-17 10:07:29.244249 [INFO] switch_cpp.cpp:1447 [ASTPP] Ratecard id : 1
  204. 2021-02-17 10:07:29.244249 [INFO] switch_cpp.cpp:1447 [ASTPP] ========================================================
  205. 2021-02-17 10:07:29.244249 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [CHECK_BLOCKED_PREFIX] Query :SELECT * FROM block_patterns WHERE (blocked_patterns ='--') AND accountid = 14 limit 1
  206. 2021-02-17 10:07:29.244249 [DEBUG] switch_cpp.cpp:1447 [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 (patterns ='--') AND accountid = 14 ORDER BY LENGTH(PKGPTR.patterns) DESC
  207. 2021-02-17 10:07:29.244249 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 1 AND status = 0
  208. 2021-02-17 10:07:29.244249 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_RATES] call_direction :
  209. 2021-02-17 10:07:29.244249 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [GET_RATES] Query :SELECT * FROM routes WHERE (pattern ='--') AND status = 0 AND (pricelist_id = 1 OR accountid=14)  ORDER BY accountid DESC,LENGTH(pattern) DESC,cost DESC LIMIT 1
  210. 2021-02-17 10:07:29.244249 [INFO] switch_cpp.cpp:1447 [ASTPP] call_direction::::::
  211. 2021-02-17 10:07:29.244249 [WARNING] switch_cpp.cpp:1447 [ASTPP] [FIND_MAXLENGTH] Rates not found!!!
  212. 2021-02-17 10:07:29.244249 [DEBUG] switch_cpp.cpp:1447 [ASTPP] post_cdrs:::0
  213. 2021-02-17 10:07:29.244249 [DEBUG] switch_core_session.c:2680 sofia/default/3855458128@65.0.179.216 ZOMBIE EXEC set(process_cdr=false)
  214. EXECUTE [depth=0] sofia/default/3855458128@65.0.179.216 set(process_cdr=false)
  215. 2021-02-17 10:07:29.244249 [DEBUG] switch_core_session.c:2889 sofia/default/3855458128@65.0.179.216 skip receive message [APPLICATION_EXEC] (channel is hungup already)
  216. 2021-02-17 10:07:29.244249 [DEBUG] mod_dptools.c:1672 SET sofia/default/3855458128@65.0.179.216 [process_cdr]=[false]
  217. 2021-02-17 10:07:29.244249 [DEBUG] switch_core_session.c:2905 sofia/default/3855458128@65.0.179.216 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
  218. 2021-02-17 10:07:29.244249 [DEBUG] switch_cpp.cpp:1447 [ASTPP] Got DTMF digits: retries:0
  219. 2021-02-17 10:07:29.244249 [DEBUG] switch_cpp.cpp:1447 [ASTPP] Got DTMF digits: retries:1
  220. 2021-02-17 10:07:29.244249 [DEBUG] switch_cpp.cpp:1447 [ASTPP] Got DTMF digits: retries:2
  221. 2021-02-17 10:07:29.244249 [DEBUG] switch_cpp.cpp:731 CoreSession::hangup
  222. 2021-02-17 10:07:29.244249 [DEBUG] switch_cpp.cpp:1191 sofia/default/3855458128@65.0.179.216 destroy/unlink session from object
  223. 2021-02-17 10:07:29.244249 [DEBUG] switch_core_session.c:2905 sofia/default/3855458128@65.0.179.216 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
  224. 2021-02-17 10:07:29.244249 [DEBUG] switch_core_state_machine.c:651 (sofia/default/3855458128@65.0.179.216) State EXECUTE going to sleep
  225. 2021-02-17 10:07:29.244249 [DEBUG] switch_core_state_machine.c:585 (sofia/default/3855458128@65.0.179.216) Running State Change CS_HANGUP (Cur 2 Tot 82327)
  226. 2021-02-17 10:07:29.244249 [DEBUG] switch_core_state_machine.c:848 (sofia/default/3855458128@65.0.179.216) Callstate Change ACTIVE -> HANGUP
  227. 2021-02-17 10:07:29.244249 [DEBUG] switch_core_state_machine.c:850 (sofia/default/3855458128@65.0.179.216) State HANGUP
  228. 2021-02-17 10:07:29.244249 [DEBUG] mod_sofia.c:453 Channel sofia/default/3855458128@65.0.179.216 hanging up, cause: NORMAL_CLEARING
  229. 2021-02-17 10:07:29.244249 [DEBUG] switch_core_state_machine.c:60 sofia/default/3855458128@65.0.179.216 Standard HANGUP, cause: NORMAL_CLEARING
  230. 2021-02-17 10:07:29.244249 [DEBUG] switch_core_state_machine.c:850 (sofia/default/3855458128@65.0.179.216) State HANGUP going to sleep
  231. 2021-02-17 10:07:29.244249 [DEBUG] switch_core_state_machine.c:620 (sofia/default/3855458128@65.0.179.216) State Change CS_HANGUP -> CS_REPORTING
  232. 2021-02-17 10:07:29.244249 [DEBUG] switch_core_state_machine.c:585 (sofia/default/3855458128@65.0.179.216) Running State Change CS_REPORTING (Cur 2 Tot 82327)
  233. 2021-02-17 10:07:29.244249 [DEBUG] switch_core_state_machine.c:936 (sofia/default/3855458128@65.0.179.216) State REPORTING
  234. 2021-02-17 10:07:29.244249 [DEBUG] switch_core_state_machine.c:174 sofia/default/3855458128@65.0.179.216 Standard REPORTING, cause: NORMAL_CLEARING
  235. 2021-02-17 10:07:29.244249 [DEBUG] switch_core_state_machine.c:936 (sofia/default/3855458128@65.0.179.216) State REPORTING going to sleep
  236. 2021-02-17 10:07:29.244249 [DEBUG] switch_core_state_machine.c:611 (sofia/default/3855458128@65.0.179.216) State Change CS_REPORTING -> CS_DESTROY
  237. 2021-02-17 10:07:29.244249 [DEBUG] switch_core_session.c:1726 Session 82326 (sofia/default/3855458128@65.0.179.216) Locked, Waiting on external entities
  238. 2021-02-17 10:07:29.244249 [NOTICE] switch_core_session.c:1744 Session 82326 (sofia/default/3855458128@65.0.179.216) Ended
  239. 2021-02-17 10:07:29.244249 [NOTICE] switch_core_session.c:1748 Close Channel sofia/default/3855458128@65.0.179.216 [CS_DESTROY]
  240. 2021-02-17 10:07:29.244249 [DEBUG] switch_core_state_machine.c:739 (sofia/default/3855458128@65.0.179.216) Running State Change CS_DESTROY (Cur 1 Tot 82327)
  241. 2021-02-17 10:07:29.244249 [DEBUG] switch_core_state_machine.c:749 (sofia/default/3855458128@65.0.179.216) State DESTROY
  242. 2021-02-17 10:07:29.244249 [DEBUG] mod_sofia.c:364 sofia/default/3855458128@65.0.179.216 SOFIA DESTROY
  243. 2021-02-17 10:07:29.244249 [DEBUG] switch_core_state_machine.c:181 sofia/default/3855458128@65.0.179.216 Standard DESTROY
  244. 2021-02-17 10:07:29.244249 [DEBUG] switch_core_state_machine.c:749 (sofia/default/3855458128@65.0.179.216) State DESTROY going to sleep
  245. 2021-02-17 10:07:29.784253 [WARNING] switch_core_state_machine.c:688 0d1ed6a3-ff94-4904-8d93-ad937bc7d8a7 sofia/default/38013801@65.0.179.216 Abandoned
  246. 2021-02-17 10:07:29.784253 [NOTICE] switch_core_state_machine.c:691 Hangup sofia/default/38013801@65.0.179.216 [CS_NEW] [WRONG_CALL_STATE]
  247. 2021-02-17 10:07:29.784253 [DEBUG] switch_core_state_machine.c:585 (sofia/default/38013801@65.0.179.216) Running State Change CS_HANGUP (Cur 1 Tot 82327)
  248. 2021-02-17 10:07:29.784253 [DEBUG] switch_core_state_machine.c:848 (sofia/default/38013801@65.0.179.216) Callstate Change DOWN -> HANGUP
  249. 2021-02-17 10:07:29.784253 [DEBUG] switch_core_state_machine.c:850 (sofia/default/38013801@65.0.179.216) State HANGUP
  250. 2021-02-17 10:07:29.784253 [DEBUG] mod_sofia.c:453 Channel sofia/default/38013801@65.0.179.216 hanging up, cause: WRONG_CALL_STATE
  251. 2021-02-17 10:07:29.784253 [DEBUG] switch_core_state_machine.c:60 sofia/default/38013801@65.0.179.216 Standard HANGUP, cause: WRONG_CALL_STATE
  252. 2021-02-17 10:07:29.784253 [DEBUG] switch_core_state_machine.c:850 (sofia/default/38013801@65.0.179.216) State HANGUP going to sleep
  253. 2021-02-17 10:07:29.784253 [DEBUG] switch_core_state_machine.c:620 (sofia/default/38013801@65.0.179.216) State Change CS_HANGUP -> CS_REPORTING
  254. 2021-02-17 10:07:29.784253 [DEBUG] switch_core_state_machine.c:585 (sofia/default/38013801@65.0.179.216) Running State Change CS_REPORTING (Cur 1 Tot 82327)
  255. 2021-02-17 10:07:29.784253 [DEBUG] switch_core_state_machine.c:936 (sofia/default/38013801@65.0.179.216) State REPORTING
  256. 2021-02-17 10:07:29.784253 [DEBUG] switch_core_state_machine.c:174 sofia/default/38013801@65.0.179.216 Standard REPORTING, cause: WRONG_CALL_STATE
  257. 2021-02-17 10:07:29.784253 [DEBUG] switch_core_state_machine.c:936 (sofia/default/38013801@65.0.179.216) State REPORTING going to sleep
  258. 2021-02-17 10:07:29.784253 [DEBUG] switch_core_state_machine.c:611 (sofia/default/38013801@65.0.179.216) State Change CS_REPORTING -> CS_DESTROY
  259. 2021-02-17 10:07:29.784253 [DEBUG] switch_core_session.c:1726 Session 82327 (sofia/default/38013801@65.0.179.216) Locked, Waiting on external entities
  260. 2021-02-17 10:07:29.784253 [NOTICE] switch_core_session.c:1744 Session 82327 (sofia/default/38013801@65.0.179.216) Ended
  261. 2021-02-17 10:07:29.784253 [NOTICE] switch_core_session.c:1748 Close Channel sofia/default/38013801@65.0.179.216 [CS_DESTROY]
  262. 2021-02-17 10:07:29.784253 [DEBUG] switch_core_state_machine.c:739 (sofia/default/38013801@65.0.179.216) Running State Change CS_DESTROY (Cur 0 Tot 82327)
  263. 2021-02-17 10:07:29.784253 [DEBUG] switch_core_state_machine.c:749 (sofia/default/38013801@65.0.179.216) State DESTROY
  264. 2021-02-17 10:07:29.784253 [DEBUG] mod_sofia.c:364 sofia/default/38013801@65.0.179.216 SOFIA DESTROY
  265. 2021-02-17 10:07:29.784253 [DEBUG] switch_core_state_machine.c:181 sofia/default/38013801@65.0.179.216 Standard DESTROY
  266. 2021-02-17 10:07:29.784253 [DEBUG] switch_core_state_machine.c:749 (sofia/default/38013801@65.0.179.216) State DESTROY going to sleep
  267. 2021-02-17 10:07:37.604245 [WARNING] sofia_reg.c:1794 SIP auth challenge (REGISTER) on sofia profile 'default' for [1686@65.0.179.216] from ip 185.217.71.236
  268. 2021-02-17 10:07:37.824286 [WARNING] sofia_reg.c:2930 Can't find user [1686@172.31.14.168] from 185.217.71.236
  269. You must define a domain called '172.31.14.168' in your directory and add a user with the id="1686" attribute
  270. and you must configure your device to use the proper domain in its authentication credentials.
  271. 2021-02-17 10:07:37.824286 [WARNING] sofia_reg.c:1739 SIP auth failure (REGISTER) on sofia profile 'default' for [1686@65.0.179.216] from ip 185.217.71.236
  272. 2021-02-17 10:07:44.344190 [NOTICE] switch_channel.c:1118 New Channel sofia/default/3855458128@65.0.179.216 [d8b386d3-ab72-4baa-ad45-ef333626cd48]
  273. 2021-02-17 10:07:44.344190 [DEBUG] switch_core_state_machine.c:585 (sofia/default/3855458128@65.0.179.216) Running State Change CS_NEW (Cur 1 Tot 82328)
  274. 2021-02-17 10:07:44.344190 [DEBUG] sofia.c:10280 sofia/default/3855458128@65.0.179.216 receiving invite from 117.247.91.162:4585 version: 1.10.5 -release-17-25569c1631 64bit
  275. 2021-02-17 10:07:44.344190 [DEBUG] sofia.c:10374 verifying acl "default" for ip/port 117.247.91.162:0.
  276. 2021-02-17 10:07:44.344190 [DEBUG] sofia.c:2434 detaching session d8b386d3-ab72-4baa-ad45-ef333626cd48
  277. 2021-02-17 10:07:44.344190 [WARNING] sofia_reg.c:1794 SIP auth challenge (INVITE) on sofia profile 'default' for [180001111@65.0.179.216] from ip 117.247.91.162
  278. 2021-02-17 10:07:44.344190 [DEBUG] switch_core_state_machine.c:604 (sofia/default/3855458128@65.0.179.216) State NEW
  279. 2021-02-17 10:07:44.384245 [DEBUG] sofia.c:2544 Re-attaching to session d8b386d3-ab72-4baa-ad45-ef333626cd48
  280. 2021-02-17 10:07:44.384245 [DEBUG] sofia.c:10280 sofia/default/3855458128@65.0.179.216 receiving invite from 117.247.91.162:4585 version: 1.10.5 -release-17-25569c1631 64bit
  281. 2021-02-17 10:07:44.384245 [DEBUG] sofia.c:10374 verifying acl "default" for ip/port 117.247.91.162:0.
  282. 2021-02-17 10:07:44.384245 [DEBUG] sofia.c:7326 Channel sofia/default/3855458128@65.0.179.216 entering state [received][100]
  283. 2021-02-17 10:07:44.384245 [DEBUG] sofia.c:7336 Remote SDP:
  284. v=0
  285. o=3855458128 1993 1906 IN IP4 117.247.91.162
  286. s=Talk
  287. c=IN IP4 117.247.91.162
  288. t=0 0
  289. m=audio 7078 RTP/AVP 124 111 110 0 8 101
  290. a=rtpmap:124 opus/48000
  291. a=fmtp:124 useinbandfec=1; usedtx=1
  292. a=rtpmap:111 speex/16000
  293. a=fmtp:111 vbr=on
  294. a=rtpmap:110 speex/8000
  295. a=fmtp:110 vbr=on
  296. a=rtpmap:101 telephone-event/8000
  297. a=fmtp:101 0-11
  298. m=video 9078 RTP/AVP 103 99
  299. a=rtpmap:103 VP8/90000
  300. a=rtpmap:99 MP4V-ES/90000
  301. a=fmtp:99 profile-level-id=3
  302.  
  303. 2021-02-17 10:07:44.384245 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [opus:124:48000:20:0:1]/[PCMA:8:8000:20:64000:1]
  304. 2021-02-17 10:07:44.384245 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [opus:124:48000:20:0:1]/[PCMU:0:8000:20:64000:1]
  305. 2021-02-17 10:07:44.384245 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [speex:111:16000:20:0:1]/[PCMA:8:8000:20:64000:1]
  306. 2021-02-17 10:07:44.384245 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [speex:111:16000:20:0:1]/[PCMU:0:8000:20:64000:1]
  307. 2021-02-17 10:07:44.384245 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [speex:110:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
  308. 2021-02-17 10:07:44.384245 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [speex:110:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
  309. 2021-02-17 10:07:44.384245 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  310. 2021-02-17 10:07:44.384245 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  311. 2021-02-17 10:07:44.384245 [DEBUG] switch_core_media.c:5649 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  312. 2021-02-17 10:07:44.384245 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  313. 2021-02-17 10:07:44.384245 [DEBUG] switch_core_media.c:5649 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  314. 2021-02-17 10:07:44.384245 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  315. 2021-02-17 10:07:44.384245 [DEBUG] switch_core_media.c:5510 Set telephone-event payload to 101@8000
  316. 2021-02-17 10:07:44.384245 [DEBUG] switch_core_media.c:3839 Set Codec sofia/default/3855458128@65.0.179.216 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
  317. 2021-02-17 10:07:44.384245 [DEBUG] switch_core_codec.c:111 sofia/default/3855458128@65.0.179.216 Original read codec set to PCMU:0
  318. 2021-02-17 10:07:44.384245 [DEBUG] switch_core_media.c:5853 Set telephone-event payload to 101@8000
  319. 2021-02-17 10:07:44.384245 [DEBUG] switch_core_media.c:5911 sofia/default/3855458128@65.0.179.216 Set 2833 dtmf send payload to 101 recv payload to 101
  320. 2021-02-17 10:07:44.384245 [DEBUG] switch_core_media.c:6239 No matches with FTMP, fallback to ignoring FMTP
  321. 2021-02-17 10:07:44.384245 [DEBUG] switch_core_media.c:6247 No matches with inherit_codec, fallback to ignoring PT
  322. 2021-02-17 10:07:44.384245 [DEBUG] sofia.c:7760 (sofia/default/3855458128@65.0.179.216) State Change CS_NEW -> CS_INIT
  323. 2021-02-17 10:07:44.384245 [DEBUG] switch_core_state_machine.c:585 (sofia/default/3855458128@65.0.179.216) Running State Change CS_INIT (Cur 1 Tot 82328)
  324. 2021-02-17 10:07:44.384245 [DEBUG] switch_core_state_machine.c:628 (sofia/default/3855458128@65.0.179.216) State INIT
  325. 2021-02-17 10:07:44.384245 [DEBUG] mod_sofia.c:93 sofia/default/3855458128@65.0.179.216 SOFIA INIT
  326. 2021-02-17 10:07:44.384245 [DEBUG] switch_core_state_machine.c:40 sofia/default/3855458128@65.0.179.216 Standard INIT
  327. 2021-02-17 10:07:44.384245 [DEBUG] switch_core_state_machine.c:48 (sofia/default/3855458128@65.0.179.216) State Change CS_INIT -> CS_ROUTING
  328. 2021-02-17 10:07:44.384245 [DEBUG] switch_core_state_machine.c:628 (sofia/default/3855458128@65.0.179.216) State INIT going to sleep
  329. 2021-02-17 10:07:44.384245 [DEBUG] switch_core_state_machine.c:585 (sofia/default/3855458128@65.0.179.216) Running State Change CS_ROUTING (Cur 1 Tot 82328)
  330. 2021-02-17 10:07:44.384245 [DEBUG] switch_channel.c:2332 (sofia/default/3855458128@65.0.179.216) Callstate Change DOWN -> RINGING
  331. 2021-02-17 10:07:44.404228 [DEBUG] switch_core_state_machine.c:644 (sofia/default/3855458128@65.0.179.216) State ROUTING
  332. 2021-02-17 10:07:44.404228 [DEBUG] mod_sofia.c:154 sofia/default/3855458128@65.0.179.216 SOFIA ROUTING
  333. 2021-02-17 10:07:44.404228 [DEBUG] switch_core_state_machine.c:236 sofia/default/3855458128@65.0.179.216 Standard ROUTING
  334. 2021-02-17 10:07:44.404228 [INFO] mod_dialplan_xml.c:637 Processing 3855458128 <3855458128>->180001111 in context default
  335. 2021-02-17 10:07:44.404228 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes')
  336. 2021-02-17 10:07:44.404228 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
  337. 2021-02-17 10:07:44.404228 [INFO] switch_cpp.cpp:1447 [ASTPP] [Dialplan] Dialed number : 180001111
  338. 2021-02-17 10:07:44.404228 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [DOAUTHORIZATION] Query :SELECT access_number FROM accessnumber WHERE access_number = '180001111' AND status=0 limit 1
  339. 2021-02-17 10:07:44.404228 [DEBUG] switch_cpp.cpp:1447 [ASTPP] Generated XML:
  340. <?xml version="1.0" encoding="UTF-8" standalone="no"?>
  341. <document type="freeswitch/xml">
  342. <section name="dialplan" description="ASTPP Dialplan">
  343. <context name="default">
  344. <extension name="180001111">
  345. <condition field="destination_number" expression="180001111">
  346. <action application="log" data="INFO ASTPP - Calling Card Call"/>
  347. <action application="answer"/>
  348. <action application="sleep" data="2000"/>
  349. <action application="lua" data="astpp-callingcards.lua"/>
  350. </condition>
  351. </extension>
  352. </context>
  353. </section>
  354. </document>
  355. Dialplan: sofia/default/3855458128@65.0.179.216 parsing [default->180001111] continue=false
  356. Dialplan: sofia/default/3855458128@65.0.179.216 Regex (PASS) [180001111] destination_number(180001111) =~ /180001111/ break=on-false
  357. Dialplan: sofia/default/3855458128@65.0.179.216 Action log(INFO ASTPP - Calling Card Call)
  358. Dialplan: sofia/default/3855458128@65.0.179.216 Action answer()
  359. Dialplan: sofia/default/3855458128@65.0.179.216 Action sleep(2000)
  360. Dialplan: sofia/default/3855458128@65.0.179.216 Action lua(astpp-callingcards.lua)
  361. 2021-02-17 10:07:44.404228 [DEBUG] switch_core_state_machine.c:287 (sofia/default/3855458128@65.0.179.216) State Change CS_ROUTING -> CS_EXECUTE
  362. 2021-02-17 10:07:44.404228 [DEBUG] switch_core_state_machine.c:644 (sofia/default/3855458128@65.0.179.216) State ROUTING going to sleep
  363. 2021-02-17 10:07:44.404228 [DEBUG] switch_core_state_machine.c:585 (sofia/default/3855458128@65.0.179.216) Running State Change CS_EXECUTE (Cur 1 Tot 82328)
  364. 2021-02-17 10:07:44.404228 [DEBUG] switch_core_state_machine.c:651 (sofia/default/3855458128@65.0.179.216) State EXECUTE
  365. 2021-02-17 10:07:44.404228 [DEBUG] mod_sofia.c:209 sofia/default/3855458128@65.0.179.216 SOFIA EXECUTE
  366. 2021-02-17 10:07:44.404228 [DEBUG] switch_core_state_machine.c:329 sofia/default/3855458128@65.0.179.216 Standard EXECUTE
  367. EXECUTE [depth=0] sofia/default/3855458128@65.0.179.216 log(INFO ASTPP - Calling Card Call)
  368. 2021-02-17 10:07:44.404228 [INFO] mod_dptools.c:1866 ASTPP - Calling Card Call
  369. EXECUTE [depth=0] sofia/default/3855458128@65.0.179.216 answer()
  370. 2021-02-17 10:07:44.404228 [DEBUG] switch_core_media.c:8663 AUDIO RTP [sofia/default/3855458128@65.0.179.216] 172.31.14.168 port 25132 -> 117.247.91.162 port 7078 codec: 0 ms: 20
  371. 2021-02-17 10:07:44.404228 [DEBUG] switch_rtp.c:4450 Starting timer [soft] 160 bytes per 20ms
  372. 2021-02-17 10:07:44.424278 [DEBUG] switch_core_media.c:8977 sofia/default/3855458128@65.0.179.216 Set 2833 dtmf send payload to 101
  373. 2021-02-17 10:07:44.424278 [DEBUG] switch_core_media.c:8984 sofia/default/3855458128@65.0.179.216 Set 2833 dtmf receive payload to 101
  374. 2021-02-17 10:07:44.424278 [DEBUG] switch_core_media.c:9007 sofia/default/3855458128@65.0.179.216 Set rtp dtmf delay to 40
  375. 2021-02-17 10:07:44.424278 [DEBUG] mod_sofia.c:898 Local SDP sofia/default/3855458128@65.0.179.216:
  376. v=0
  377. o=FreeSWITCH 1613531332 1613531333 IN IP4 65.0.179.216
  378. s=FreeSWITCH
  379. c=IN IP4 65.0.179.216
  380. t=0 0
  381. m=audio 25132 RTP/AVP 0 101
  382. a=rtpmap:0 PCMU/8000
  383. a=rtpmap:101 telephone-event/8000
  384. a=fmtp:101 0-16
  385. a=ptime:20
  386. a=sendrecv
  387. m=video 0 RTP/AVP 19
  388.  
  389. 2021-02-17 10:07:44.424278 [DEBUG] sofia.c:7326 Channel sofia/default/3855458128@65.0.179.216 entering state [completed][200]
  390. 2021-02-17 10:07:44.424278 [NOTICE] mod_dptools.c:1406 Channel [sofia/default/3855458128@65.0.179.216] has been answered
  391. 2021-02-17 10:07:44.424278 [DEBUG] switch_channel.c:3865 (sofia/default/3855458128@65.0.179.216) Callstate Change RINGING -> ACTIVE
  392. EXECUTE [depth=0] sofia/default/3855458128@65.0.179.216 sleep(2000)
  393. 2021-02-17 10:07:44.484247 [DEBUG] sofia.c:7326 Channel sofia/default/3855458128@65.0.179.216 entering state [ready][200]
  394. 2021-02-17 10:07:44.544223 [DEBUG] switch_rtp.c:7759 Correct audio ip/port confirmed.
  395. freeswitch@ip-172-31-14-168>
  396. freeswitch@ip-172-31-14-168>
  397. EXECUTE [depth=0] sofia/default/3855458128@65.0.179.216 lua(astpp-callingcards.lua)
  398. 2021-02-17 10:07:46.464224 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes')
  399. 2021-02-17 10:07:46.464224 [NOTICE] switch_cpp.cpp:1447 [ASTPP] SECTION
  400. 2021-02-17 10:07:46.464224 [DEBUG] switch_core_file.c:405 File /usr/share/freeswitch/sounds/en/us/callie/astpp-welcome.wav sample rate 16000 doesn't match requested rate 8000
  401. 2021-02-17 10:07:46.464224 [DEBUG] switch_ivr_play_say.c:1488 Codec Activated L16@8000hz 1 channels 20ms
  402. freeswitch@ip-172-31-14-168>
  403. freeswitch@ip-172-31-14-168>
  404. freeswitch@ip-172-31-14-168>
  405. freeswitch@ip-172-31-14-168>
  406. freeswitch@ip-172-31-14-168>
  407. freeswitch@ip-172-31-14-168>
  408. freeswitch@ip-172-31-14-168>
  409. freeswitch@ip-172-31-14-168>
  410. freeswitch@ip-172-31-14-168>
  411. freeswitch@ip-172-31-14-168>
  412. freeswitch@ip-172-31-14-168>
  413. freeswitch@ip-172-31-14-168>
  414. freeswitch@ip-172-31-14-168>
  415. freeswitch@ip-172-31-14-168>
  416. freeswitch@ip-172-31-14-168>
  417. freeswitch@ip-172-31-14-168>
  418. freeswitch@ip-172-31-14-168>
  419. freeswitch@ip-172-31-14-168>
  420. freeswitch@ip-172-31-14-168>
  421. freeswitch@ip-172-31-14-168>
  422. freeswitch@ip-172-31-14-168>
  423. freeswitch@ip-172-31-14-168>
  424. freeswitch@ip-172-31-14-168>
  425. freeswitch@ip-172-31-14-168>
  426. freeswitch@ip-172-31-14-168>
  427. freeswitch@ip-172-31-14-168>
  428. freeswitch@ip-172-31-14-168>
  429. freeswitch@ip-172-31-14-168>
  430. freeswitch@ip-172-31-14-168>
  431. 2021-02-17 10:07:48.244244 [DEBUG] switch_ivr_play_say.c:1933 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-welcome.wav
  432. 2021-02-17 10:07:48.244244 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [CHECK_DID] Query :SELECT * FROM ani_map WHERE number = 3855458128
  433. freeswitch@ip-172-31-14-168>
  434. 2021-02-17 10:07:48.264224 [DEBUG] switch_core_file.c:405 File /usr/share/freeswitch/sounds/en/us/callie/astpp-accountnum.wav sample rate 16000 doesn't match requested rate 8000
  435. 2021-02-17 10:07:48.264224 [DEBUG] switch_ivr_play_say.c:1488 Codec Activated L16@8000hz 1 channels 20ms
  436. freeswitch@ip-172-31-14-168>
  437. 2021-02-17 10:07:51.244325 [DEBUG] switch_ivr_play_say.c:1933 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-accountnum.wav
  438. 2021-02-17 10:07:55.784241 [DEBUG] switch_rtp.c:8004 RTP RECV DTMF 1:800
  439. 2021-02-17 10:07:55.784241 [INFO] switch_channel.c:522 RECV DTMF 1:800
  440. 2021-02-17 10:07:56.544245 [DEBUG] switch_rtp.c:8004 RTP RECV DTMF 4:800
  441. 2021-02-17 10:07:56.544245 [INFO] switch_channel.c:522 RECV DTMF 4:800
  442. 2021-02-17 10:07:56.904245 [NOTICE] switch_channel.c:1118 New Channel sofia/default/38013801@65.0.179.216 [7454dc0b-5b6e-4e8c-9b5c-ec6a9b121fa9]
  443. 2021-02-17 10:07:56.904245 [DEBUG] switch_core_state_machine.c:585 (sofia/default/38013801@65.0.179.216) Running State Change CS_NEW (Cur 2 Tot 82329)
  444. 2021-02-17 10:07:56.904245 [DEBUG] sofia.c:10280 sofia/default/38013801@65.0.179.216 receiving invite from 23.146.241.14:58121 version: 1.10.5 -release-17-25569c1631 64bit
  445. 2021-02-17 10:07:56.904245 [DEBUG] sofia.c:10374 verifying acl "default" for ip/port 23.146.241.14:0.
  446. 2021-02-17 10:07:56.904245 [DEBUG] sofia.c:2434 detaching session 7454dc0b-5b6e-4e8c-9b5c-ec6a9b121fa9
  447. 2021-02-17 10:07:56.904245 [WARNING] sofia_reg.c:1794 SIP auth challenge (INVITE) on sofia profile 'default' for [9442037694911@65.0.179.216] from ip 23.146.241.14
  448. 2021-02-17 10:07:56.904245 [DEBUG] switch_core_state_machine.c:604 (sofia/default/38013801@65.0.179.216) State NEW
  449. 2021-02-17 10:07:57.664195 [DEBUG] switch_rtp.c:8004 RTP RECV DTMF #:800
  450. 2021-02-17 10:07:57.664195 [INFO] switch_channel.c:522 RECV DTMF #:800
  451. 2021-02-17 10:07:57.684233 [DEBUG] switch_cpp.cpp:1447 [ASTPP] Got DTMF digits: 14
  452. 2021-02-17 10:07:57.684233 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [DOAUTHORIZATION] Query :SELECT *,(select currencyrate from currency where id=currency_id) as currencyrate FROM accounts WHERE (number = "14" OR id="14") AND status=0 AND deleted=0 limit 1
  453. 2021-02-17 10:07:57.684233 [DEBUG] switch_core_file.c:405 File /usr/share/freeswitch/sounds/en/us/callie/astpp-pleasepin.wav sample rate 16000 doesn't match requested rate 8000
  454. 2021-02-17 10:07:57.684233 [DEBUG] switch_ivr_play_say.c:1488 Codec Activated L16@8000hz 1 channels 20ms
  455. 2021-02-17 10:08:00.384246 [DEBUG] switch_ivr_play_say.c:1933 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-pleasepin.wav
  456. 2021-02-17 10:08:06.984246 [WARNING] switch_core_state_machine.c:688 7454dc0b-5b6e-4e8c-9b5c-ec6a9b121fa9 sofia/default/38013801@65.0.179.216 Abandoned
  457. 2021-02-17 10:08:06.984246 [NOTICE] switch_core_state_machine.c:691 Hangup sofia/default/38013801@65.0.179.216 [CS_NEW] [WRONG_CALL_STATE]
  458. 2021-02-17 10:08:06.984246 [DEBUG] switch_core_state_machine.c:585 (sofia/default/38013801@65.0.179.216) Running State Change CS_HANGUP (Cur 2 Tot 82329)
  459. 2021-02-17 10:08:06.984246 [DEBUG] switch_core_state_machine.c:848 (sofia/default/38013801@65.0.179.216) Callstate Change DOWN -> HANGUP
  460. 2021-02-17 10:08:06.984246 [DEBUG] switch_core_state_machine.c:850 (sofia/default/38013801@65.0.179.216) State HANGUP
  461. 2021-02-17 10:08:06.984246 [DEBUG] mod_sofia.c:453 Channel sofia/default/38013801@65.0.179.216 hanging up, cause: WRONG_CALL_STATE
  462. 2021-02-17 10:08:06.984246 [DEBUG] switch_core_state_machine.c:60 sofia/default/38013801@65.0.179.216 Standard HANGUP, cause: WRONG_CALL_STATE
  463. 2021-02-17 10:08:06.984246 [DEBUG] switch_core_state_machine.c:850 (sofia/default/38013801@65.0.179.216) State HANGUP going to sleep
  464. 2021-02-17 10:08:06.984246 [DEBUG] switch_core_state_machine.c:620 (sofia/default/38013801@65.0.179.216) State Change CS_HANGUP -> CS_REPORTING
  465. 2021-02-17 10:08:06.984246 [DEBUG] switch_core_state_machine.c:585 (sofia/default/38013801@65.0.179.216) Running State Change CS_REPORTING (Cur 2 Tot 82329)
  466. 2021-02-17 10:08:06.984246 [DEBUG] switch_core_state_machine.c:936 (sofia/default/38013801@65.0.179.216) State REPORTING
  467. 2021-02-17 10:08:06.984246 [DEBUG] switch_core_state_machine.c:174 sofia/default/38013801@65.0.179.216 Standard REPORTING, cause: WRONG_CALL_STATE
  468. 2021-02-17 10:08:06.984246 [DEBUG] switch_core_state_machine.c:936 (sofia/default/38013801@65.0.179.216) State REPORTING going to sleep
  469. 2021-02-17 10:08:06.984246 [DEBUG] switch_core_state_machine.c:611 (sofia/default/38013801@65.0.179.216) State Change CS_REPORTING -> CS_DESTROY
  470. 2021-02-17 10:08:06.984246 [DEBUG] switch_core_session.c:1726 Session 82329 (sofia/default/38013801@65.0.179.216) Locked, Waiting on external entities
  471. 2021-02-17 10:08:06.984246 [NOTICE] switch_core_session.c:1744 Session 82329 (sofia/default/38013801@65.0.179.216) Ended
  472. 2021-02-17 10:08:06.984246 [NOTICE] switch_core_session.c:1748 Close Channel sofia/default/38013801@65.0.179.216 [CS_DESTROY]
  473. 2021-02-17 10:08:06.984246 [DEBUG] switch_core_state_machine.c:739 (sofia/default/38013801@65.0.179.216) Running State Change CS_DESTROY (Cur 1 Tot 82329)
  474. 2021-02-17 10:08:06.984246 [DEBUG] switch_core_state_machine.c:749 (sofia/default/38013801@65.0.179.216) State DESTROY
  475. 2021-02-17 10:08:06.984246 [DEBUG] mod_sofia.c:364 sofia/default/38013801@65.0.179.216 SOFIA DESTROY
  476. 2021-02-17 10:08:06.984246 [DEBUG] switch_core_state_machine.c:181 sofia/default/38013801@65.0.179.216 Standard DESTROY
  477. 2021-02-17 10:08:06.984246 [DEBUG] switch_core_state_machine.c:749 (sofia/default/38013801@65.0.179.216) State DESTROY going to sleep
  478. 2021-02-17 10:08:08.484225 [DEBUG] switch_rtp.c:8004 RTP RECV DTMF 4:800
  479. 2021-02-17 10:08:08.484225 [INFO] switch_channel.c:522 RECV DTMF 4:800
  480. 2021-02-17 10:08:09.924245 [DEBUG] switch_rtp.c:8004 RTP RECV DTMF 2:800
  481. 2021-02-17 10:08:09.924245 [INFO] switch_channel.c:522 RECV DTMF 2:800
  482. 2021-02-17 10:08:11.524247 [DEBUG] switch_rtp.c:8004 RTP RECV DTMF 3:800
  483. 2021-02-17 10:08:11.524247 [INFO] switch_channel.c:522 RECV DTMF 3:800
  484. 2021-02-17 10:08:12.564245 [DEBUG] switch_rtp.c:8004 RTP RECV DTMF 8:800
  485. 2021-02-17 10:08:12.564245 [INFO] switch_channel.c:522 RECV DTMF 8:800
  486. 2021-02-17 10:08:13.264316 [DEBUG] switch_rtp.c:8004 RTP RECV DTMF 0:800
  487. 2021-02-17 10:08:13.264316 [INFO] switch_channel.c:522 RECV DTMF 0:800
  488. 2021-02-17 10:08:14.464243 [DEBUG] switch_rtp.c:8004 RTP RECV DTMF 2:800
  489. 2021-02-17 10:08:14.464243 [INFO] switch_channel.c:522 RECV DTMF 2:800
  490. 2021-02-17 10:08:15.604249 [DEBUG] switch_rtp.c:8004 RTP RECV DTMF #:800
  491. 2021-02-17 10:08:15.604249 [INFO] switch_channel.c:522 RECV DTMF #:800
  492. 2021-02-17 10:08:15.604249 [DEBUG] switch_cpp.cpp:1447 [ASTPP] We recieved a pin : 423802
  493. 2021-02-17 10:08:15.604249 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [validate_card_usage] Query :SELECT DATE_FORMAT('2031-02-14 09:49:05' , '%Y%m%d%H%i%s') AS expiry
  494. 2021-02-17 10:08:15.604249 [DEBUG] switch_cpp.cpp:1447 [ASTPP] [validate_card_usage] Query :SELECT DATE_FORMAT('2021-02-17 10:08:15' , '%Y%m%d%H%i%s') AS expiry
  495. 2021-02-17 10:08:15.624228 [DEBUG] switch_core_file.c:405 File /usr/share/freeswitch/sounds/en/us/callie/astpp-register.wav sample rate 16000 doesn't match requested rate 8000
  496. 2021-02-17 10:08:15.624228 [DEBUG] switch_ivr_play_say.c:1488 Codec Activated L16@8000hz 1 channels 20ms
  497. 2021-02-17 10:08:16.384231 [WARNING] sofia_reg.c:1794 SIP auth challenge (REGISTER) on sofia profile 'default' for [3085@65.0.179.216] from ip 185.217.71.236
  498. 2021-02-17 10:08:16.644249 [WARNING] sofia_reg.c:2930 Can't find user [3085@172.31.14.168] from 185.217.71.236
  499. You must define a domain called '172.31.14.168' in your directory and add a user with the id="3085" attribute
  500. and you must configure your device to use the proper domain in its authentication credentials.
  501. 2021-02-17 10:08:16.644249 [WARNING] sofia_reg.c:1739 SIP auth failure (REGISTER) on sofia profile 'default' for [3085@65.0.179.216] from ip 185.217.71.236
  502. 2021-02-17 10:08:18.424250 [DEBUG] switch_ivr_play_say.c:1933 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-register.wav
  503. 2021-02-17 10:08:23.424250 [NOTICE] switch_cpp.cpp:1447 [ASTPP] [Accountcode : 1594415095]
  504. 2021-02-17 10:08:23.424250 [DEBUG] switch_core_file.c:405 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
  505. 2021-02-17 10:08:23.424250 [DEBUG] switch_ivr_play_say.c:1488 Codec Activated L16@8000hz 1 channels 20ms
  506.