FreeSWITCH Pastebin

Freeswitch-logs

From Kdorcas71, 1 Year ago, written in FreeSWITCH.
- view diff
URL https://pastebin.freeswitch.org/view/b66ad290
Embed
Download Paste or View Raw
  1. 2022-06-29 11:18:29.829697 98.37% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [689@102.220.200.133] from ip 62.197.144.11
  2. 2022-06-29 11:18:56.229690 99.43% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [768@102.220.200.133] from ip 62.197.148.4
  3. 2022-06-29 11:18:56.909630 99.27% [WARNING] sofia_reg.c:3223 Can't find user [768@102.220.200.133] from 62.197.148.4
  4. You must define a domain called '102.220.200.133' in your directory and add a user with the id="768" attribute
  5. and you must configure your device to use the proper domain in its authentication credentials.
  6. 2022-06-29 11:18:56.909630 99.27% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [768@102.220.200.133] from ip 62.197.148.4
  7. freeswitch@pbx>
  8. freeswitch@pbx>
  9. 2022-06-29 11:19:36.549694 99.30% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [741@102.220.200.133] from ip 45.129.32.39
  10. 2022-06-29 11:19:37.129695 99.33% [WARNING] sofia_reg.c:3223 Can't find user [741@102.220.200.133] from 45.129.32.39
  11. You must define a domain called '102.220.200.133' in your directory and add a user with the id="741" attribute
  12. and you must configure your device to use the proper domain in its authentication credentials.
  13. 2022-06-29 11:19:37.129695 99.33% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [741@102.220.200.133] from ip 45.129.32.39
  14. 2022-06-29 11:19:52.289698 99.33% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [690@102.220.200.133] from ip 212.102.48.16
  15. 2022-06-29 11:19:52.509691 99.33% [WARNING] sofia_reg.c:3223 Can't find user [690@102.220.200.133] from 212.102.48.16
  16. You must define a domain called '102.220.200.133' in your directory and add a user with the id="690" attribute
  17. and you must configure your device to use the proper domain in its authentication credentials.
  18. 2022-06-29 11:19:52.509691 99.33% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [690@102.220.200.133] from ip 212.102.48.16
  19. 2022-06-29 11:19:53.769698 99.33% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [767@102.220.200.133] from ip 89.37.173.54
  20. 2022-06-29 11:19:53.969694 99.33% [WARNING] sofia_reg.c:3223 Can't find user [767@102.220.200.133] from 89.37.173.54
  21. You must define a domain called '102.220.200.133' in your directory and add a user with the id="767" attribute
  22. and you must configure your device to use the proper domain in its authentication credentials.
  23. 2022-06-29 11:19:53.969694 99.33% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [767@102.220.200.133] from ip 89.37.173.54
  24. 2022-06-29 11:19:58.729699 99.17% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [575@102.220.200.133] from ip 45.136.155.49
  25. 2022-06-29 11:19:59.189699 99.17% [WARNING] sofia_reg.c:3223 Can't find user [575@102.220.200.133] from 45.136.155.49
  26. You must define a domain called '102.220.200.133' in your directory and add a user with the id="575" attribute
  27. and you must configure your device to use the proper domain in its authentication credentials.
  28. 2022-06-29 11:19:59.189699 99.17% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [575@102.220.200.133] from ip 45.136.155.49
  29. 2022-06-29 11:20:18.869689 98.57% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [761@102.220.200.133] from ip 194.169.170.4
  30. 2022-06-29 11:20:19.349664 98.57% [WARNING] sofia_reg.c:3223 Can't find user [761@102.220.200.133] from 194.169.170.4
  31. You must define a domain called '102.220.200.133' in your directory and add a user with the id="761" attribute
  32. and you must configure your device to use the proper domain in its authentication credentials.
  33. 2022-06-29 11:20:19.349664 98.57% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [761@102.220.200.133] from ip 194.169.170.4
  34. 2022-06-29 11:20:29.169695 98.67% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 212.102.40.87
  35. 2022-06-29 11:20:29.609664 98.67% [WARNING] sofia_reg.c:3223 Can't find user [769@102.220.200.133] from 212.102.40.87
  36. You must define a domain called '102.220.200.133' in your directory and add a user with the id="769" attribute
  37. and you must configure your device to use the proper domain in its authentication credentials.
  38. 2022-06-29 11:20:29.609664 98.67% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 212.102.40.87
  39. 2022-06-29 11:20:42.369699 99.37% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [768@102.220.200.133] from ip 138.199.60.166
  40. 2022-06-29 11:20:43.949694 99.33% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [766@102.220.200.133] from ip 45.136.155.56
  41. 2022-06-29 11:20:44.369645 99.33% [WARNING] sofia_reg.c:3223 Can't find user [766@102.220.200.133] from 45.136.155.56
  42. You must define a domain called '102.220.200.133' in your directory and add a user with the id="766" attribute
  43. and you must configure your device to use the proper domain in its authentication credentials.
  44. 2022-06-29 11:20:44.369645 99.33% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [766@102.220.200.133] from ip 45.136.155.56
  45. 2022-06-29 11:21:14.269691 97.53% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [690@102.220.200.133] from ip 143.244.42.103
  46. 2022-06-29 11:21:14.529700 97.53% [WARNING] sofia_reg.c:3223 Can't find user [690@102.220.200.133] from 143.244.42.103
  47. You must define a domain called '102.220.200.133' in your directory and add a user with the id="690" attribute
  48. and you must configure your device to use the proper domain in its authentication credentials.
  49. 2022-06-29 11:21:14.529700 97.53% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [690@102.220.200.133] from ip 143.244.42.103
  50. 2022-06-29 11:21:32.409693 98.50% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 45.136.155.91
  51. 2022-06-29 11:21:32.649695 99.00% [WARNING] sofia_reg.c:3223 Can't find user [769@102.220.200.133] from 45.136.155.91
  52. You must define a domain called '102.220.200.133' in your directory and add a user with the id="769" attribute
  53. and you must configure your device to use the proper domain in its authentication credentials.
  54. 2022-06-29 11:21:32.649695 99.00% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 45.136.155.91
  55. 2022-06-29 11:21:38.769692 99.40% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [4023@102.220.200.133] from ip 85.14.245.202
  56. 2022-06-29 11:21:40.009696 99.40% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [768@102.220.200.133] from ip 85.204.124.94
  57. 2022-06-29 11:21:40.429702 99.40% [WARNING] sofia_reg.c:3223 Can't find user [768@102.220.200.133] from 85.204.124.94
  58. You must define a domain called '102.220.200.133' in your directory and add a user with the id="768" attribute
  59. and you must configure your device to use the proper domain in its authentication credentials.
  60. 2022-06-29 11:21:40.429702 99.40% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [768@102.220.200.133] from ip 85.204.124.94
  61. 2022-06-29 11:21:49.209707 97.77% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [766@102.220.200.133] from ip 45.134.224.25
  62. 2022-06-29 11:21:49.769627 97.63% [WARNING] sofia_reg.c:3223 Can't find user [766@102.220.200.133] from 45.134.224.25
  63. You must define a domain called '102.220.200.133' in your directory and add a user with the id="766" attribute
  64. and you must configure your device to use the proper domain in its authentication credentials.
  65. 2022-06-29 11:21:49.769627 97.63% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [766@102.220.200.133] from ip 45.134.224.25
  66. 2022-06-29 11:21:55.649691 95.73% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [653@102.220.200.133] from ip 92.62.120.6
  67. 2022-06-29 11:21:55.849673 95.73% [WARNING] sofia_reg.c:3223 Can't find user [653@102.220.200.133] from 92.62.120.6
  68. You must define a domain called '102.220.200.133' in your directory and add a user with the id="653" attribute
  69. and you must configure your device to use the proper domain in its authentication credentials.
  70. 2022-06-29 11:21:55.849673 95.73% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [653@102.220.200.133] from ip 92.62.120.6
  71. 2022-06-29 11:21:56.289698 95.73% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 62.197.148.11
  72. 2022-06-29 11:21:56.589694 95.73% [WARNING] sofia_reg.c:3223 Can't find user [769@102.220.200.133] from 62.197.148.11
  73. You must define a domain called '102.220.200.133' in your directory and add a user with the id="769" attribute
  74. and you must configure your device to use the proper domain in its authentication credentials.
  75. 2022-06-29 11:21:56.589694 95.73% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 62.197.148.11
  76. 2022-06-29 11:22:19.369674 95.83% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [676@102.220.200.133] from ip 62.197.144.9
  77. 2022-06-29 11:22:29.249695 97.90% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [687@102.220.200.133] from ip 193.218.35.13
  78. 2022-06-29 11:22:29.849694 98.07% [WARNING] sofia_reg.c:3223 Can't find user [687@102.220.200.133] from 193.218.35.13
  79. You must define a domain called '102.220.200.133' in your directory and add a user with the id="687" attribute
  80. and you must configure your device to use the proper domain in its authentication credentials.
  81. 2022-06-29 11:22:29.849694 98.07% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [687@102.220.200.133] from ip 193.218.35.13
  82. 2022-06-29 11:23:19.469642 98.30% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [766@102.220.200.133] from ip 62.197.152.9
  83. 2022-06-29 11:23:20.669689 98.27% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [672@102.220.200.133] from ip 93.190.138.235
  84. 2022-06-29 11:23:20.909692 98.27% [WARNING] sofia_reg.c:3223 Can't find user [672@102.220.200.133] from 93.190.138.235
  85. You must define a domain called '102.220.200.133' in your directory and add a user with the id="672" attribute
  86. and you must configure your device to use the proper domain in its authentication credentials.
  87. 2022-06-29 11:23:20.909692 98.27% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [672@102.220.200.133] from ip 93.190.138.235
  88. 2022-06-29 11:23:26.669693 98.37% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [689@102.220.200.133] from ip 156.146.45.104
  89. 2022-06-29 11:23:27.309662 98.37% [WARNING] sofia_reg.c:3223 Can't find user [689@102.220.200.133] from 156.146.45.104
  90. You must define a domain called '102.220.200.133' in your directory and add a user with the id="689" attribute
  91. and you must configure your device to use the proper domain in its authentication credentials.
  92. 2022-06-29 11:23:27.309662 98.37% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [689@102.220.200.133] from ip 156.146.45.104
  93. 2022-06-29 11:23:29.469692 98.47% [NOTICE] switch_channel.c:1123 New Channel sofia/default/0902@102.220.200.133 [c77f3a33-e1b5-4002-a208-36f81f0e0384]
  94. 2022-06-29 11:23:29.469692 98.47% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_NEW (Cur 1 Tot 703)
  95. 2022-06-29 11:23:29.469692 98.47% [INFO] sofia.c:10462 sofia/default/0902@102.220.200.133 receiving invite from 102.220.201.145:5060 version: 1.10.7 -release-19-883d2cb662 64bit call-id: 5ecd981b-c1505d22@102.220.201.145
  96. 2022-06-29 11:23:29.469692 98.47% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 102.220.201.145:0.
  97. 2022-06-29 11:23:29.469692 98.47% [WARNING] sofia_reg.c:1861 SIP auth challenge (INVITE) on sofia profile 'default' for [0000@102.220.200.133] from ip 102.220.201.145
  98. 2022-06-29 11:23:29.469692 98.47% [DEBUG] switch_core_state_machine.c:600 (sofia/default/0902@102.220.200.133) State NEW
  99. 2022-06-29 11:23:29.469692 98.47% [DEBUG] sofia.c:2419 detaching session c77f3a33-e1b5-4002-a208-36f81f0e0384
  100. 2022-06-29 11:23:29.489628 98.47% [DEBUG] sofia.c:2532 Re-attaching to session c77f3a33-e1b5-4002-a208-36f81f0e0384
  101. 2022-06-29 11:23:29.489628 98.47% [INFO] sofia.c:10462 sofia/default/0902@102.220.200.133 receiving invite from 102.220.201.145:5060 version: 1.10.7 -release-19-883d2cb662 64bit call-id: 5ecd981b-c1505d22@102.220.201.145
  102. 2022-06-29 11:23:29.489628 98.47% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 102.220.201.145:0.
  103. 2022-06-29 11:23:29.509637 98.47% [DEBUG] sofia.c:7499 Channel sofia/default/0902@102.220.200.133 entering state [received][100]
  104. 2022-06-29 11:23:29.509637 98.47% [DEBUG] sofia.c:7509 Remote SDP:
  105. v=0
  106. o=- 14867458 14867458 IN IP4 102.220.201.145
  107. s=-
  108. c=IN IP4 102.220.201.145
  109. t=0 0
  110. m=audio 16536 RTP/AVP 0 2 8 9 18 96 97 98 101
  111. a=rtpmap:0 PCMU/8000
  112. a=rtpmap:2 G726-32/8000
  113. a=rtpmap:8 PCMA/8000
  114. a=rtpmap:9 G722/8000
  115. a=rtpmap:18 G729a/8000
  116. a=rtpmap:96 G726-40/8000
  117. a=rtpmap:97 G726-24/8000
  118. a=rtpmap:98 G726-16/8000
  119. a=rtpmap:101 telephone-event/8000
  120. a=fmtp:101 0-15
  121. a=ptime:30
  122.  
  123. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:30:64000:1]/[PCMA:8:8000:20:64000:1]
  124. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:30:64000:1]/[PCMU:0:8000:20:64000:1]
  125. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5686 Audio Codec Compare [PCMU:0:8000:20:64000:1] is saved as a near-match
  126. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-32:2:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
  127. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-32:2:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
  128. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:30:64000:1]/[PCMA:8:8000:20:64000:1]
  129. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5686 Audio Codec Compare [PCMA:8:8000:20:64000:1] is saved as a near-match
  130. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:30:64000:1]/[PCMU:0:8000:20:64000:1]
  131. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G722:9:8000:30:64000:1]/[PCMA:8:8000:20:64000:1]
  132. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G722:9:8000:30:64000:1]/[PCMU:0:8000:20:64000:1]
  133. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729a:18:8000:30:8000:1]/[PCMA:8:8000:20:64000:1]
  134. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729a:18:8000:30:8000:1]/[PCMU:0:8000:20:64000:1]
  135. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-40:96:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
  136. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-40:96:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
  137. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-24:97:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
  138. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-24:97:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
  139. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-16:98:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
  140. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-16:98:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
  141. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5566 Set telephone-event payload to 101@8000
  142. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5757 Substituting codec PCMU@30i@8000h@1c
  143. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:3870 Set Codec sofia/default/0902@102.220.200.133 PCMU/8000 30 ms 240 samples 64000 bits 1 channels
  144. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_codec.c:111 sofia/default/0902@102.220.200.133 Original read codec set to PCMU:0
  145. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5915 Set telephone-event payload to 101@8000
  146. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:5973 sofia/default/0902@102.220.200.133 Set 2833 dtmf send payload to 101 recv payload to 101
  147. 2022-06-29 11:23:29.509637 98.47% [DEBUG] sofia.c:7933 (sofia/default/0902@102.220.200.133) State Change CS_NEW -> CS_INIT
  148. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_INIT (Cur 1 Tot 703)
  149. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_state_machine.c:624 (sofia/default/0902@102.220.200.133) State INIT
  150. 2022-06-29 11:23:29.509637 98.47% [DEBUG] mod_sofia.c:97 sofia/default/0902@102.220.200.133 SOFIA INIT
  151. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_state_machine.c:40 sofia/default/0902@102.220.200.133 Standard INIT
  152. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_state_machine.c:48 (sofia/default/0902@102.220.200.133) State Change CS_INIT -> CS_ROUTING
  153. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_state_machine.c:624 (sofia/default/0902@102.220.200.133) State INIT going to sleep
  154. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_ROUTING (Cur 1 Tot 703)
  155. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_channel.c:2380 (sofia/default/0902@102.220.200.133) Callstate Change DOWN -> RINGING
  156. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_state_machine.c:640 (sofia/default/0902@102.220.200.133) State ROUTING
  157. 2022-06-29 11:23:29.509637 98.47% [DEBUG] mod_sofia.c:158 sofia/default/0902@102.220.200.133 SOFIA ROUTING
  158. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_state_machine.c:230 sofia/default/0902@102.220.200.133 Standard ROUTING
  159. 2022-06-29 11:23:29.509637 98.47% [INFO] mod_dialplan_xml.c:639 Processing 0902 <0902>->0000 in context default
  160. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes')
  161. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
  162. 2022-06-29 11:23:29.509637 98.47% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] Dialed number : 0000
  163. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT access_number FROM accessnumber WHERE access_number = '0000' AND status=0 limit 1
  164. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Generated XML:
  165. <?xml version="1.0" encoding="UTF-8" standalone="no"?>
  166. <document type="freeswitch/xml">
  167. <section name="dialplan" description="ASTPP Dialplan">
  168. <context name="default">
  169. <extension name="0000">
  170. <condition field="destination_number" expression="0000">
  171. <action application="log" data="INFO ASTPP - Calling Card Call"/>
  172. <action application="answer"/>
  173. <action application="sleep" data="2000"/>
  174. <action application="lua" data="astpp-callingcards.lua"/>
  175. </condition>
  176. </extension>
  177. </context>
  178. </section>
  179. </document>
  180. Dialplan: sofia/default/0902@102.220.200.133 parsing [default->0000] continue=false
  181. Dialplan: sofia/default/0902@102.220.200.133 Regex (PASS) [0000] destination_number(0000) =~ /0000/ break=on-false
  182. Dialplan: sofia/default/0902@102.220.200.133 Action log(INFO ASTPP - Calling Card Call)
  183. Dialplan: sofia/default/0902@102.220.200.133 Action answer()
  184. Dialplan: sofia/default/0902@102.220.200.133 Action sleep(2000)
  185. Dialplan: sofia/default/0902@102.220.200.133 Action lua(astpp-callingcards.lua)
  186. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_state_machine.c:281 (sofia/default/0902@102.220.200.133) State Change CS_ROUTING -> CS_EXECUTE
  187. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_state_machine.c:640 (sofia/default/0902@102.220.200.133) State ROUTING going to sleep
  188. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_EXECUTE (Cur 1 Tot 703)
  189. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_state_machine.c:647 (sofia/default/0902@102.220.200.133) State EXECUTE
  190. 2022-06-29 11:23:29.509637 98.47% [DEBUG] mod_sofia.c:213 sofia/default/0902@102.220.200.133 SOFIA EXECUTE
  191. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_state_machine.c:323 sofia/default/0902@102.220.200.133 Standard EXECUTE
  192. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 log(INFO ASTPP - Calling Card Call)
  193. 2022-06-29 11:23:29.509637 98.47% [INFO] mod_dptools.c:1879 ASTPP - Calling Card Call
  194. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 answer()
  195. 2022-06-29 11:23:29.509637 98.47% [DEBUG] switch_core_media.c:8777 AUDIO RTP [sofia/default/0902@102.220.200.133] 102.220.200.133 port 17842 -> 102.220.201.145 port 16536 codec: 0 ms: 30
  196. 2022-06-29 11:23:29.529616 98.47% [DEBUG] switch_rtp.c:4619 Starting timer [soft] 240 bytes per 30ms
  197. 2022-06-29 11:23:29.549641 98.47% [DEBUG] switch_core_media.c:9089 sofia/default/0902@102.220.200.133 Set 2833 dtmf send payload to 101
  198. 2022-06-29 11:23:29.549641 98.47% [DEBUG] switch_core_media.c:9096 sofia/default/0902@102.220.200.133 Set 2833 dtmf receive payload to 101
  199. 2022-06-29 11:23:29.549641 98.47% [DEBUG] switch_core_media.c:9119 sofia/default/0902@102.220.200.133 Set rtp dtmf delay to 40
  200. 2022-06-29 11:23:29.549641 98.47% [DEBUG] mod_sofia.c:913 Local SDP sofia/default/0902@102.220.200.133:
  201. v=0
  202. o=FreeSWITCH 1656473167 1656473168 IN IP4 102.220.200.133
  203. s=FreeSWITCH
  204. c=IN IP4 102.220.200.133
  205. t=0 0
  206. m=audio 17842 RTP/AVP 0 101
  207. a=rtpmap:0 PCMU/8000
  208. a=rtpmap:101 telephone-event/8000
  209. a=fmtp:101 0-15
  210. a=ptime:30
  211. a=sendrecv
  212.  
  213. 2022-06-29 11:23:29.549641 98.47% [NOTICE] mod_dptools.c:1419 Channel [sofia/default/0902@102.220.200.133] has been answered
  214. 2022-06-29 11:23:29.549641 98.47% [DEBUG] switch_channel.c:3950 (sofia/default/0902@102.220.200.133) Callstate Change RINGING -> ACTIVE
  215. 2022-06-29 11:23:29.549641 98.47% [DEBUG] sofia.c:7499 Channel sofia/default/0902@102.220.200.133 entering state [completed][200]
  216. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 sleep(2000)
  217. 2022-06-29 11:23:29.669641 98.43% [DEBUG] sofia.c:7499 Channel sofia/default/0902@102.220.200.133 entering state [ready][200]
  218. 2022-06-29 11:23:29.689688 98.43% [DEBUG] switch_rtp.c:7934 Correct audio ip/port confirmed.
  219. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 lua(astpp-callingcards.lua)
  220. 2022-06-29 11:23:31.569700 98.37% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes')
  221. 2022-06-29 11:23:31.589620 98.37% [NOTICE] switch_cpp.cpp:1465 [ASTPP] SECTION
  222. 2022-06-29 11:23:31.589620 98.37% [DEBUG] switch_core_file.c:444 File /var/www/html/astpp/upload/astpp-welcome.wav sample rate 16000 doesn't match requested rate 8000
  223. 2022-06-29 11:23:31.589620 98.37% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  224. 2022-06-29 11:23:33.349699 98.93% [DEBUG] switch_ivr_play_say.c:2001 done playing file /var/www/html/astpp/upload/astpp-welcome.wav
  225. 2022-06-29 11:23:33.369672 98.93% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-accountnum.wav sample rate 16000 doesn't match requested rate 8000
  226. 2022-06-29 11:23:33.369672 98.93% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  227. 2022-06-29 11:23:36.349693 99.10% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-accountnum.wav
  228. 2022-06-29 11:23:38.289678 99.17% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:1040
  229. 2022-06-29 11:23:38.289678 99.17% [INFO] switch_channel.c:527 RECV DTMF 7:1040
  230. 2022-06-29 11:23:38.709691 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:1200
  231. 2022-06-29 11:23:38.709691 99.13% [INFO] switch_channel.c:527 RECV DTMF 1:1200
  232. 2022-06-29 11:23:39.169694 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 8:1200
  233. 2022-06-29 11:23:39.169694 99.13% [INFO] switch_channel.c:527 RECV DTMF 8:1200
  234. 2022-06-29 11:23:39.669690 99.17% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF #:2000
  235. span style="color: green; font-weight: bold;"> 2022-06-29 11:23:39.669690 99.17% [INFO] switch_channel.c:527 RECV DTMF #:2000
  236. span style="color: goldenrod; font-weight: bold;"> 2022-06-29 11:23:39.689644 99.17% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Got DTMF digits: 718
  237. 2022-06-29 11:23:39.689644 99.17% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT *,(select currencyrate from currency where id=currency_id) as currencyrate FROM accounts WHERE number = "718" AND status=0 AND deleted=0 limit 1
  238. 2022-06-29 11:23:39.689644 99.17% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-badaccount.wav sample rate 16000 doesn't match requested rate 8000
  239. 2022-06-29 11:23:39.689644 99.17% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  240. 2022-06-29 11:23:41.289691 99.17% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-badaccount.wav
  241. 2022-06-29 11:23:41.309659 99.17% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-accountnum.wav sample rate 16000 doesn't match requested rate 8000
  242. 2022-06-29 11:23:41.309659 99.17% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  243. 2022-06-29 11:23:44.289628 99.10% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-accountnum.wav
  244. 2022-06-29 11:23:44.629699 99.10% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:1520
  245. 2022-06-29 11:23:44.629699 99.10% [INFO] switch_channel.c:527 RECV DTMF 1:1520
  246. 2022-06-29 11:23:45.049695 99.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 2:1200
  247. 2022-06-29 11:23:45.049695 99.07% [INFO] switch_channel.c:527 RECV DTMF 2:1200
  248. 2022-06-29 11:23:45.429698 99.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:1040
  249. 2022-06-29 11:23:45.429698 99.07% [INFO] switch_channel.c:527 RECV DTMF 7:1040
  250. 2022-06-29 11:23:45.709690 99.10% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:960
  251. 2022-06-29 11:23:45.709690 99.10% [INFO] switch_channel.c:527 RECV DTMF 7:960
  252. 2022-06-29 11:23:46.069655 99.10% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:1200
  253. 2022-06-29 11:23:46.069655 99.10% [INFO] switch_channel.c:527 RECV DTMF 1:1200
  254. 2022-06-29 11:23:46.509690 99.10% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 8:1360
  255. 2022-06-29 11:23:46.509690 99.10% [INFO] switch_channel.c:527 RECV DTMF 8:1360
  256. 2022-06-29 11:23:46.969669 99.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF #:1760
  257. span style="color: green; font-weight: bold;"> 2022-06-29 11:23:46.969669 99.07% [INFO] switch_channel.c:527 RECV DTMF #:1760
  258. span style="color: goldenrod; font-weight: bold;"> 2022-06-29 11:23:46.969669 99.07% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Got DTMF digits: 127718
  259. 2022-06-29 11:23:46.969669 99.07% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT *,(select currencyrate from currency where id=currency_id) as currencyrate FROM accounts WHERE number = "127718" AND status=0 AND deleted=0 limit 1
  260. 2022-06-29 11:23:46.989702 99.07% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-pleasepin.wav sample rate 16000 doesn't match requested rate 8000
  261. 2022-06-29 11:23:46.989702 99.07% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  262. 2022-06-29 11:23:49.689695 99.17% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-pleasepin.wav
  263. 2022-06-29 11:23:50.709692 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 6:1360
  264. 2022-06-29 11:23:50.709692 99.13% [INFO] switch_channel.c:527 RECV DTMF 6:1360
  265. 2022-06-29 11:23:50.989700 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 3:960
  266. 2022-06-29 11:23:50.989700 99.13% [INFO] switch_channel.c:527 RECV DTMF 3:960
  267. 2022-06-29 11:23:51.369694 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:1040
  268. 2022-06-29 11:23:51.369694 99.13% [INFO] switch_channel.c:527 RECV DTMF 1:1040
  269. 2022-06-29 11:23:51.709645 99.17% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 4:1040
  270. 2022-06-29 11:23:51.709645 99.17% [INFO] switch_channel.c:527 RECV DTMF 4:1040
  271. 2022-06-29 11:23:52.269690 99.17% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF #:1840
  272. span style="color: green; font-weight: bold;"> 2022-06-29 11:23:52.269690 99.17% [INFO] switch_channel.c:527 RECV DTMF #:1840
  273. span style="color: goldenrod; font-weight: bold;"> 2022-06-29 11:23:52.289641 99.17% [DEBUG] switch_cpp.cpp:1465 [ASTPP] We recieved a pin : 6314
  274. 2022-06-29 11:23:52.289641 99.17% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [validate_card_usage] Query :SELECT DATE_FORMAT('2032-06-21 10:11:08' , '%Y%m%d%H%i%s') AS expiry
  275. 2022-06-29 11:23:52.289641 99.17% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [validate_card_usage] Query :SELECT DATE_FORMAT('2022-06-29 08:23:52' , '%Y%m%d%H%i%s') AS expiry
  276. 2022-06-29 11:23:52.289641 99.17% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [Accountcode : 127718]
  277. 2022-06-29 11:23:52.289641 99.17% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-this-card-has-a-balance-of.wav sample rate 16000 doesn't match requested rate 8000
  278. 2022-06-29 11:23:52.289641 99.17% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  279. 2022-06-29 11:23:53.589691 99.13% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-this-card-has-a-balance-of.wav
  280. 2022-06-29 11:23:53.609640 99.13% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [Play Amount First Part] Query :5000
  281. 2022-06-29 11:23:53.609640 99.13% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [Play Amount Second Part] Query :00
  282. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 say(en number pronounced 5000)
  283. 2022-06-29 11:23:53.629633 99.13% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  284. 2022-06-29 11:23:54.829692 99.10% [DEBUG] switch_ivr_play_say.c:2001 done playing file file_string://digits/5.wav!digits/thousand.wav
  285. 2022-06-29 11:23:54.829692 99.10% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-point.wav sample rate 16000 doesn't match requested rate 8000
  286. 2022-06-29 11:23:54.849637 99.10% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  287. 2022-06-29 11:23:55.389693 99.10% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-point.wav
  288. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 say(en number pronounced 00)
  289. 2022-06-29 11:23:55.429635 99.10% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  290. 2022-06-29 11:23:56.169702 99.07% [DEBUG] switch_ivr_play_say.c:2001 done playing file file_string://digits/0.wav
  291. 2022-06-29 11:23:56.209664 99.07% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-phonenum.wav sample rate 16000 doesn't match requested rate 8000
  292. 2022-06-29 11:23:56.209664 99.07% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  293. 2022-06-29 11:23:59.889694 98.77% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-phonenum.wav
  294. 2022-06-29 11:24:00.169684 98.77% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 0:1680
  295. 2022-06-29 11:24:00.169684 98.77% [INFO] switch_channel.c:527 RECV DTMF 0:1680
  296. 2022-06-29 11:24:00.529697 98.77% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:960
  297. 2022-06-29 11:24:00.529697 98.77% [INFO] switch_channel.c:527 RECV DTMF 7:960
  298. 2022-06-29 11:24:00.949695 98.80% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 9:720
  299. 2022-06-29 11:24:00.949695 98.80% [INFO] switch_channel.c:527 RECV DTMF 9:720
  300. 2022-06-29 11:24:02.109691 98.67% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 9:1120
  301. 2022-06-29 11:24:02.109691 98.67% [INFO] switch_channel.c:527 RECV DTMF 9:1120
  302. 2022-06-29 11:24:02.529691 98.67% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 2:960
  303. 2022-06-29 11:24:02.529691 98.67% [INFO] switch_channel.c:527 RECV DTMF 2:960
  304. 2022-06-29 11:24:02.949662 98.50% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 0:1360
  305. 2022-06-29 11:24:02.949662 98.50% [INFO] switch_channel.c:527 RECV DTMF 0:1360
  306. 2022-06-29 11:24:03.249672 98.50% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 5:720
  307. 2022-06-29 11:24:03.249672 98.50% [INFO] switch_channel.c:527 RECV DTMF 5:720
  308. 2022-06-29 11:24:03.609691 98.50% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 0:1040
  309. 2022-06-29 11:24:03.609691 98.50% [INFO] switch_channel.c:527 RECV DTMF 0:1040
  310. 2022-06-29 11:24:03.969679 98.50% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 9:1200
  311. 2022-06-29 11:24:03.969679 98.50% [INFO] switch_channel.c:527 RECV DTMF 9:1200
  312. 2022-06-29 11:24:04.309693 98.50% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:1040
  313. 2022-06-29 11:24:04.309693 98.50% [INFO] switch_channel.c:527 RECV DTMF 7:1040
  314. 2022-06-29 11:24:04.729694 98.50% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF #:1200
  315. span style="color: green; font-weight: bold;"> 2022-06-29 11:24:04.729694 98.50% [INFO] switch_channel.c:527 RECV DTMF #:1200
  316. span style="color: green; font-weight: bold;"> 2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] [CHECK_destination] Dialed destination number :0799205097
  317. 2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Account Information ===================
  318. 2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] User id : 17
  319. 2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] Account code : 127718
  320. 2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] Balance : 5000
  321. 2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] Type : 0 [0:prepaid,1:postpaid]
  322. 2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] Ratecard id : 4
  323. 2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] ========================================================
  324. 2022-06-29 11:24:04.729694 98.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CHECK_BLOCKED_PREFIX] Query :SELECT * FROM block_patterns WHERE (blocked_patterns = '^0799205097.*' OR blocked_patterns = '^079920509.*' OR blocked_patterns = '^07992050.*' OR blocked_patterns = '^0799205.*' OR blocked_patterns = '^079920.*' OR blocked_patterns = '^07992.*' OR blocked_patterns = '^0799.*' OR blocked_patterns = '^079.*' OR blocked_patterns = '^07.*' OR blocked_patterns = '^0.*' OR blocked_patterns ='--') AND accountid = 17 limit 1
  325. 2022-06-29 11:24:04.729694 98.50% [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 (patterns = '^0799205097.*' OR patterns = '^079920509.*' OR patterns = '^07992050.*' OR patterns = '^0799205.*' OR patterns = '^079920.*' OR patterns = '^07992.*' OR patterns = '^0799.*' OR patterns = '^079.*' OR patterns = '^07.*' OR patterns = '^0.*' OR patterns ='--') AND accountid = 17 ORDER BY LENGTH(PKGPTR.patterns) DESC
  326. 2022-06-29 11:24:04.729694 98.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 4 AND status = 0
  327. 2022-06-29 11:24:04.729694 98.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_RATES] call_direction :
  328. 2022-06-29 11:24:04.729694 98.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_RATES] Query :SELECT * FROM routes WHERE (pattern = '^0799205097.*' OR pattern = '^079920509.*' OR pattern = '^07992050.*' OR pattern = '^0799205.*' OR pattern = '^079920.*' OR pattern = '^07992.*' OR pattern = '^0799.*' OR pattern = '^079.*' OR pattern = '^07.*' OR pattern = '^0.*' OR pattern ='--') AND status = 0 AND (pricelist_id = 4 OR accountid=17)  ORDER BY accountid DESC,LENGTH(pattern) DESC,cost DESC LIMIT 1
  329. 2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] call_direction::::::
  330. 2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Rates Information ===================
  331. 2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] ID : 11
  332. 2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] Connectcost : 0.00000
  333. 2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] Includedseconds : 0
  334. 2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] Cost : 220.00000
  335. 2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] comment : Uganda
  336. 2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] Country Id : 197
  337. 2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] Accid : 17
  338. 2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] Trunk ID: 3
  339. 2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] Routing type:
  340. 2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] ================================================================
  341. 2022-06-29 11:24:04.729694 98.50% [INFO] switch_cpp.cpp:1465 [ASTPP] [FIND_MAXLENGTH] Your5000 balance Accountid 17 !!!
  342. 2022-06-29 11:24:04.729694 98.50% [NOTICE] switch_cpp.cpp:1465 [ASTPP] 22 Minutes
  343. 2022-06-29 11:24:04.729694 98.50% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [SAY_TIMELIMIT] MINUTES 22
  344. 2022-06-29 11:24:04.729694 98.50% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-this-call-will-last.wav sample rate 16000 doesn't match requested rate 8000
  345. 2022-06-29 11:24:04.729694 98.50% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  346. 2022-06-29 11:24:05.929692 98.50% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-this-call-will-last.wav
  347. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 say(en number pronounced 22)
  348. 2022-06-29 11:24:05.969646 98.50% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  349. 2022-06-29 11:24:07.029692 98.43% [DEBUG] switch_ivr_play_say.c:2001 done playing file file_string://digits/20.wav!digits/2.wav
  350. 2022-06-29 11:24:07.069658 98.43% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-minutes.wav sample rate 16000 doesn't match requested rate 8000
  351. 2022-06-29 11:24:07.069658 98.43% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  352. 2022-06-29 11:24:07.669698 98.43% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-minutes.wav
  353. 2022-06-29 11:24:07.669698 98.43% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_CARRIER_RATES] Query :SELECT TK.id as trunk_id,TK.name as trunk_name,TK.codec,GW.name as path,GW.dialplan_variable,TK.provider_id,TR.init_inc,TK.status,TK.maxchannels,TK.cps,TK.leg_timeout,TR.pattern,TR.id as outbound_route_id,TR.connectcost,TR.comment,TR.includedseconds,TR.cost,TR.inc,TR.prepend,TR.strip,(select name from gateways where status=0 AND id = TK.failover_gateway_id) as path1,(select name from gateways where status=0 AND id = TK.failover_gateway_id1) as path2 FROM outbound_routes as TR,trunks as TK,gateways as GW WHERE GW.status=0 AND GW.id= TK.gateway_id AND TK.status=0 AND TK.id= TR.trunk_id AND (pattern = '^0799205097.*' OR pattern = '^079920509.*' OR pattern = '^07992050.*' OR pattern = '^0799205.*' OR pattern = '^079920.*' OR pattern = '^07992.*' OR pattern = '^0799.*' OR pattern = '^079.*' OR pattern = '^07.*' OR pattern = '^0.*' OR pattern ='--') AND TR.status = 0  AND TR.trunk_id IN (3)  ORDER by LENGTH (pattern) DESC,TR.cost ASC,TR.precedence ASC, TK.precedence
  354. 2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Termination Rates Information ===================
  355. 2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] ID : 7
  356. 2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] Code : ^0.*
  357. 2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] Destination : Uganda
  358. 2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] Connectcost : 0.00000
  359. 2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] Free Seconds : 0
  360. 2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] Prefix : ^0.*
  361. 2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] Strip :
  362. 2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] Termination rate id : 3
  363. 2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] Gateway name : MTN
  364. 2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] Failover gateway :
  365. 2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] Vendor id : 18
  366. 2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] Max channels : 0
  367. 2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] trunk_name : MTN
  368. 2022-06-29 11:24:07.709680 98.43% [INFO] switch_cpp.cpp:1465 [ASTPP] =================================================================
  369. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(call_processed=internal)
  370. 2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [call_processed]=[internal]
  371. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(callstart=2022-06-29 08:24:07)
  372. 2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [callstart]=[2022-06-29 08:24:07]
  373. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(originated_destination_number=0799205097)
  374. 2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [originated_destination_number]=[0799205097]
  375. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(effective_destination_number=0799205097)
  376. 2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [effective_destination_number]=[0799205097]
  377. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(continue_on_fail=true)
  378. 2022-06-29 11:24:07.709680 98.43% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [continue_on_fail]=[true]
  379. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(hangup_after_bridge=true)
  380. 2022-06-29 11:24:07.709680 98.43% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [hangup_after_bridge]=[true]
  381. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(account_id=17)
  382. 2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [account_id]=[17]
  383. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(account_type=0)
  384. 2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [account_type]=[0]
  385. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(resellerid=0)
  386. 2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [resellerid]=[0]
  387. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(parent_id=0)
  388. 2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [parent_id]=[0]
  389. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(accountcode=127718)
  390. 2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [accountcode]=[127718]
  391. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(call_direction=outbound)
  392. 2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [call_direction]=[outbound]
  393. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(calltype=CALLINGCARD)
  394. 2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [calltype]=[CALLINGCARD]
  395. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(origination_rates=ID:11|CODE:^0.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:|COST:220.00000|INC:2|INITIALBLOCK:1|RATEGROUP:4|MARKUP:0|CI:197|ACCID:17)
  396. 2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [origination_rates]=[ID:11|CODE:^0.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:|COST:220.00000|INC:2|INITIALBLOCK:1|RATEGROUP:4|MARKUP:0|CI:197|ACCID:17]
  397. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(execute_on_answer=sched_hangup +1320)
  398. 2022-06-29 11:24:07.709680 98.43% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [execute_on_answer]=[sched_hangup +1320]
  399. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(process_cdr=true)
  400. 2022-06-29 11:24:07.709680 98.43% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [process_cdr]=[true]
  401. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 sched_hangup(+1320)
  402. 2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_scheduler.c:263 Added task 4 switch_ivr_schedule_hangup (c77f3a33-e1b5-4002-a208-36f81f0e0384) to run at 1656492367
  403. 2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_OVERRIDE_CALLERID] Query :SELECT callerid_name as cid_name,callerid_number as cid_number,accountid FROM accounts_callerid WHERE accountid = 17 AND status=0 LIMIT 1
  404. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(original_caller_id_name=0902)
  405. 2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [original_caller_id_name]=[0902]
  406. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(original_caller_id_number=0902)
  407. 2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [original_caller_id_number]=[0902]
  408. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(presence_data=x|||Dorcas(127718)|||^0.* // Uganda // 220.00000|||MTN // ^0.* // Uganda // 220.00000|||CC)
  409. 2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [presence_data]=[x|||Dorcas(127718)|||^0.* // Uganda // 220.00000|||MTN // ^0.* // Uganda // 220.00000|||CC]
  410. 2022-06-29 11:24:07.709680 98.43% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,out_caller_id_terminate,number_terminate FROM localization WHERE id=(SELECT localization_id from accounts where id = 18) AND status=0 limit 1
  411. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(termination_rates=ID:7|CODE:^0.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:220.00000|INC:0|TRUNK:3|PROVIDER:18)
  412. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [termination_rates]=[ID:7|CODE:^0.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:220.00000|INC:0|TRUNK:3|PROVIDER:18]
  413. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(trunk_id=3)
  414. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [trunk_id]=[3]
  415. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(provider_id=18)
  416. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [provider_id]=[18]
  417. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(hangup_after_bridge=false)
  418. 2022-06-29 11:24:07.729624 98.43% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [hangup_after_bridge]=[false]
  419. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(absolute_codec_string=PCMA,G729,PCMA)
  420. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [absolute_codec_string]=[PCMA,G729,PCMA]
  421. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 bridge([leg_timeout=0]sofia/gateway/MTN/0799205097)
  422. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1954 (sofia/default/0902@102.220.200.133) Callstate Change ACTIVE -> RING_WAIT
  423. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [call_processed]=[internal] to event
  424. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [callstart]=[2022-06-29 08:24:07] to event
  425. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [originated_destination_number]=[0799205097] to event
  426. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [effective_destination_number]=[0799205097] to event
  427. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [account_id]=[17] to event
  428. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [account_type]=[0] to event
  429. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [resellerid]=[0] to event
  430. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [parent_id]=[0] to event
  431. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [accountcode]=[127718] to event
  432. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [call_direction]=[outbound] to event
  433. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [calltype]=[CALLINGCARD] to event
  434. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [origination_rates]=[ID:11|CODE:^0.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:|COST:220.00000|INC:2|INITIALBLOCK:1|RATEGROUP:4|MARKUP:0|CI:197|ACCID:17] to event
  435. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [original_caller_id_name]=[0902] to event
  436. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [original_caller_id_number]=[0902] to event
  437. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [presence_data]=[x|||Dorcas(127718)|||^0.* // Uganda // 220.00000|||MTN // ^0.* // Uganda // 220.00000|||CC] to event
  438. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [termination_rates]=[ID:7|CODE:^0.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:220.00000|INC:0|TRUNK:3|PROVIDER:18] to event
  439. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [trunk_id]=[3] to event
  440. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [provider_id]=[18] to event
  441. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [absolute_codec_string]=[PCMA,G729,PCMA] to event
  442. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
  443. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_ivr_originate.c:2843 Parsing session specific variables
  444. 2022-06-29 11:24:07.729624 98.43% [NOTICE] switch_channel.c:1123 New Channel sofia/default/0799205097 [0d73108c-c92d-4782-8abf-9a3de7c43c2c]
  445. 2022-06-29 11:24:07.729624 98.43% [DEBUG] mod_sofia.c:5121 (sofia/default/0799205097) State Change CS_NEW -> CS_INIT
  446. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0799205097) Running State Change CS_INIT (Cur 2 Tot 704)
  447. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:624 (sofia/default/0799205097) State INIT
  448. 2022-06-29 11:24:07.729624 98.43% [DEBUG] mod_sofia.c:97 sofia/default/0799205097 SOFIA INIT
  449. 2022-06-29 11:24:07.729624 98.43% [INFO] sofia_glue.c:1651 sofia/default/0799205097 sending invite call-id: (null)
  450. 2022-06-29 11:24:07.729624 98.43% [DEBUG] sofia_glue.c:1654 sofia/default/0799205097 sending invite version: 1.10.7 -release-19-883d2cb662 64bit
  451. Local SDP:
  452. v=0
  453. o=FreeSWITCH 1656469267 1656469268 IN IP4 102.220.200.133
  454. s=FreeSWITCH
  455. c=IN IP4 102.220.200.133
  456. t=0 0
  457. m=audio 21780 RTP/AVP 8 18 101
  458. a=rtpmap:8 PCMA/8000
  459. a=rtpmap:18 G729/8000
  460. a=rtpmap:101 telephone-event/8000
  461. a=fmtp:101 0-15
  462. a=ptime:20
  463. a=sendrecv
  464.  
  465. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:40 sofia/default/0799205097 Standard INIT
  466. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:48 (sofia/default/0799205097) State Change CS_INIT -> CS_ROUTING
  467. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:624 (sofia/default/0799205097) State INIT going to sleep
  468. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0799205097) Running State Change CS_ROUTING (Cur 2 Tot 704)
  469. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:640 (sofia/default/0799205097) State ROUTING
  470. 2022-06-29 11:24:07.729624 98.43% [DEBUG] mod_sofia.c:158 sofia/default/0799205097 SOFIA ROUTING
  471. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_ivr_originate.c:67 (sofia/default/0799205097) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  472. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:640 (sofia/default/0799205097) State ROUTING going to sleep
  473. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0799205097) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 704)
  474. 2022-06-29 11:24:07.729624 98.43% [DEBUG] sofia.c:7499 Channel sofia/default/0799205097 entering state [calling][0]
  475. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:659 (sofia/default/0799205097) State CONSUME_MEDIA
  476. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:659 (sofia/default/0799205097) State CONSUME_MEDIA going to sleep
  477. 2022-06-29 11:24:07.729624 98.43% [DEBUG] sofia.c:7499 Channel sofia/default/0799205097 entering state [terminated][503]
  478. 2022-06-29 11:24:07.729624 98.43% [NOTICE] sofia.c:8738 Hangup sofia/default/0799205097 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE]
  479. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0799205097) Running State Change CS_HANGUP (Cur 2 Tot 704)
  480. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:844 (sofia/default/0799205097) Callstate Change DOWN -> HANGUP
  481. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:846 (sofia/default/0799205097) State HANGUP
  482. 2022-06-29 11:24:07.729624 98.43% [DEBUG] mod_sofia.c:468 Channel sofia/default/0799205097 hanging up, cause: NORMAL_TEMPORARY_FAILURE
  483. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE]
  484. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:59 sofia/default/0799205097 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
  485. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:846 (sofia/default/0799205097) State HANGUP going to sleep
  486. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:616 (sofia/default/0799205097) State Change CS_HANGUP -> CS_REPORTING
  487. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0799205097) Running State Change CS_REPORTING (Cur 2 Tot 704)
  488. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_state_machine.c:932 (sofia/default/0799205097) State REPORTING
  489. 2022-06-29 11:24:07.729624 98.43% [INFO] mod_json_cdr.c:271 Process [0d73108c-c92d-4782-8abf-9a3de7c43c2c.cdr.json]
  490. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_channel.c:2178 (sofia/default/0902@102.220.200.133) Callstate Change RING_WAIT -> ACTIVE
  491. 2022-06-29 11:24:07.729624 98.43% [INFO] mod_dptools.c:3653 Originate Failed.  Cause: NORMAL_TEMPORARY_FAILURE
  492. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-callingcard-menu.wav sample rate 16000 doesn't match requested rate 8000
  493. 2022-06-29 11:24:07.729624 98.43% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  494. 2022-06-29 11:24:07.789618 98.43% [DEBUG] switch_core_state_machine.c:168 sofia/default/0799205097 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
  495. 2022-06-29 11:24:07.789618 98.43% [DEBUG] switch_core_state_machine.c:932 (sofia/default/0799205097) State REPORTING going to sleep
  496. 2022-06-29 11:24:07.789618 98.43% [DEBUG] switch_core_state_machine.c:607 (sofia/default/0799205097) State Change CS_REPORTING -> CS_DESTROY
  497. 2022-06-29 11:24:07.789618 98.43% [DEBUG] switch_core_session.c:1753 Session 704 (sofia/default/0799205097) Locked, Waiting on external entities
  498. 2022-06-29 11:24:07.789618 98.43% [NOTICE] switch_core_session.c:1771 Session 704 (sofia/default/0799205097) Ended
  499. 2022-06-29 11:24:07.789618 98.43% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/0799205097 [CS_DESTROY]
  500. 2022-06-29 11:24:07.789618 98.43% [DEBUG] switch_core_state_machine.c:735 (sofia/default/0799205097) Running State Change CS_DESTROY (Cur 1 Tot 704)
  501. 2022-06-29 11:24:07.789618 98.43% [DEBUG] switch_core_state_machine.c:745 (sofia/default/0799205097) State DESTROY
  502. 2022-06-29 11:24:07.789618 98.43% [DEBUG] mod_sofia.c:379 sofia/default/0799205097 SOFIA DESTROY
  503. 2022-06-29 11:24:07.789618 98.43% [DEBUG] switch_core_state_machine.c:175 sofia/default/0799205097 Standard DESTROY
  504. 2022-06-29 11:24:07.789618 98.43% [DEBUG] switch_core_state_machine.c:745 (sofia/default/0799205097) State DESTROY going to sleep
  505. 2022-06-29 11:24:13.849696 98.10% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-callingcard-menu.wav
  506. 2022-06-29 11:24:19.389630 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:1760
  507. 2022-06-29 11:24:19.389630 98.07% [INFO] switch_channel.c:527 RECV DTMF 1:1760
  508. 2022-06-29 11:24:19.409639 98.07% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Got DTMF digits: 1retries:0
  509. 2022-06-29 11:24:19.409639 98.07% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT *,(select currencyrate from currency where id=currency_id) as currencyrate FROM accounts WHERE number = "17" AND status=0 AND deleted=0 limit 1
  510. 2022-06-29 11:24:19.409639 98.07% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-phonenum.wav sample rate 16000 doesn't match requested rate 8000
  511. 2022-06-29 11:24:19.409639 98.07% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  512. 2022-06-29 11:24:22.329670 98.07% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [686@102.220.200.133] from ip 2.58.241.4
  513. 2022-06-29 11:24:22.389692 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 0:1360
  514. 2022-06-29 11:24:22.389692 98.07% [INFO] switch_channel.c:527 RECV DTMF 0:1360
  515. 2022-06-29 11:24:22.409633 98.07% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-phonenum.wav
  516. 2022-06-29 11:24:22.689694 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:640
  517. 2022-06-29 11:24:22.689694 98.07% [INFO] switch_channel.c:527 RECV DTMF 7:640
  518. 2022-06-29 11:24:22.749689 98.07% [WARNING] sofia_reg.c:3223 Can't find user [686@102.220.200.133] from 2.58.241.4
  519. You must define a domain called '102.220.200.133' in your directory and add a user with the id="686" attribute
  520. and you must configure your device to use the proper domain in its authentication credentials.
  521. 2022-06-29 11:24:22.749689 98.07% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [686@102.220.200.133] from ip 2.58.241.4
  522. 2022-06-29 11:24:22.989670 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:800
  523. 2022-06-29 11:24:22.989670 98.07% [INFO] switch_channel.c:527 RECV DTMF 7:800
  524. 2022-06-29 11:24:23.409693 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 9:1200
  525. 2022-06-29 11:24:23.409693 98.07% [INFO] switch_channel.c:527 RECV DTMF 9:1200
  526. 2022-06-29 11:24:23.829694 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 2:1280
  527. 2022-06-29 11:24:23.829694 98.07% [INFO] switch_channel.c:527 RECV DTMF 2:1280
  528. 2022-06-29 11:24:24.549697 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 0:1840
  529. 2022-06-29 11:24:24.549697 98.07% [INFO] switch_channel.c:527 RECV DTMF 0:1840
  530. 2022-06-29 11:24:25.009663 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 5:1040
  531. 2022-06-29 11:24:25.009663 98.07% [INFO] switch_channel.c:527 RECV DTMF 5:1040
  532. 2022-06-29 11:24:25.389694 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 0:1280
  533. 2022-06-29 11:24:25.389694 98.07% [INFO] switch_channel.c:527 RECV DTMF 0:1280
  534. 2022-06-29 11:24:25.749697 98.10% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 9:1040
  535. 2022-06-29 11:24:25.749697 98.10% [INFO] switch_channel.c:527 RECV DTMF 9:1040
  536. 2022-06-29 11:24:26.089694 98.10% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:800
  537. 2022-06-29 11:24:26.089694 98.10% [INFO] switch_channel.c:527 RECV DTMF 7:800
  538. 2022-06-29 11:24:26.529694 98.10% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF #:1360
  539. span style="color: green; font-weight: bold;"> 2022-06-29 11:24:26.529694 98.10% [INFO] switch_channel.c:527 RECV DTMF #:1360
  540. span style="color: green; font-weight: bold;"> 2022-06-29 11:24:26.549644 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] [CHECK_destination] Dialed destination number :0779205097
  541. 2022-06-29 11:24:26.549644 98.10% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Account Information ===================
  542. 2022-06-29 11:24:26.549644 98.10% [ERR] mod_lua.cpp:202 ...switch/scripts/astpp/lib/astpp.callingcard.functions.lua:598: attempt to index local 'userinfo' (a nil value)
  543. stack traceback:
  544.         ...switch/scripts/astpp/lib/astpp.callingcard.functions.lua:598: in function 'process_destination'
  545.         ...switch/scripts/astpp/lib/astpp.callingcard.functions.lua:259: in function 'playback_ivr'
  546.         /usr/share/freeswitch/scripts/astpp-callingcards.lua:106: in main chunk
  547. 2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_cpp.cpp:1209 sofia/default/0902@102.220.200.133 destroy/unlink session from object
  548. 2022-06-29 11:24:26.549644 98.10% [NOTICE] switch_core_state_machine.c:382 sofia/default/0902@102.220.200.133 has executed the last dialplan instruction, hanging up.
  549. 2022-06-29 11:24:26.549644 98.10% [NOTICE] switch_core_state_machine.c:384 Hangup sofia/default/0902@102.220.200.133 [CS_EXECUTE] [NORMAL_CLEARING]
  550. 2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:647 (sofia/default/0902@102.220.200.133) State EXECUTE going to sleep
  551. 2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_HANGUP (Cur 1 Tot 704)
  552. 2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:844 (sofia/default/0902@102.220.200.133) Callstate Change ACTIVE -> HANGUP
  553. 2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:846 (sofia/default/0902@102.220.200.133) State HANGUP
  554. 2022-06-29 11:24:26.549644 98.10% [DEBUG] mod_sofia.c:462 sofia/default/0902@102.220.200.133 Overriding SIP cause 480 with 503 from the other leg
  555. 2022-06-29 11:24:26.549644 98.10% [DEBUG] mod_sofia.c:468 Channel sofia/default/0902@102.220.200.133 hanging up, cause: NORMAL_CLEARING
  556. 2022-06-29 11:24:26.549644 98.10% [DEBUG] mod_sofia.c:522 Sending BYE to sofia/default/0902@102.220.200.133
  557. 2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:59 sofia/default/0902@102.220.200.133 Standard HANGUP, cause: NORMAL_CLEARING
  558. 2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:846 (sofia/default/0902@102.220.200.133) State HANGUP going to sleep
  559. 2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:616 (sofia/default/0902@102.220.200.133) State Change CS_HANGUP -> CS_REPORTING
  560. 2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_REPORTING (Cur 1 Tot 704)
  561. 2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:932 (sofia/default/0902@102.220.200.133) State REPORTING
  562. 2022-06-29 11:24:26.549644 98.10% [INFO] mod_json_cdr.c:271 Process [c77f3a33-e1b5-4002-a208-36f81f0e0384.cdr.json]
  563. 2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:168 sofia/default/0902@102.220.200.133 Standard REPORTING, cause: NORMAL_CLEARING
  564. 2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:932 (sofia/default/0902@102.220.200.133) State REPORTING going to sleep
  565. 2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:607 (sofia/default/0902@102.220.200.133) State Change CS_REPORTING -> CS_DESTROY
  566. 2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_session.c:1753 Session 703 (sofia/default/0902@102.220.200.133) Locked, Waiting on external entities
  567. 2022-06-29 11:24:26.549644 98.10% [NOTICE] switch_core_session.c:1771 Session 703 (sofia/default/0902@102.220.200.133) Ended
  568. 2022-06-29 11:24:26.549644 98.10% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/0902@102.220.200.133 [CS_DESTROY]
  569. 2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:735 (sofia/default/0902@102.220.200.133) Running State Change CS_DESTROY (Cur 0 Tot 704)
  570. 2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:745 (sofia/default/0902@102.220.200.133) State DESTROY
  571. 2022-06-29 11:24:26.549644 98.10% [DEBUG] mod_sofia.c:379 sofia/default/0902@102.220.200.133 SOFIA DESTROY
  572. 2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:175 sofia/default/0902@102.220.200.133 Standard DESTROY
  573. 2022-06-29 11:24:26.549644 98.10% [DEBUG] switch_core_state_machine.c:745 (sofia/default/0902@102.220.200.133) State DESTROY going to sleep
  574. 2022-06-29 11:24:26.689694 98.23% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [691@102.220.200.133] from ip 213.109.151.9
  575. 2022-06-29 11:24:26.709694 98.23% [DEBUG] switch_scheduler.c:147 Deleting task 4 switch_ivr_schedule_hangup (c77f3a33-e1b5-4002-a208-36f81f0e0384)
  576. 2022-06-29 11:24:47.429690 99.17% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [669@102.220.200.133] from ip 103.219.21.17
  577. 2022-06-29 11:25:08.789690 97.90% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [768@102.220.200.133] from ip 91.240.243.18
  578. 2022-06-29 11:25:09.069694 97.90% [WARNING] sofia_reg.c:3223 Can't find user [768@102.220.200.133] from 91.240.243.18
  579. You must define a domain called '102.220.200.133' in your directory and add a user with the id="768" attribute
  580. and you must configure your device to use the proper domain in its authentication credentials.
  581. 2022-06-29 11:25:09.069694 97.90% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [768@102.220.200.133] from ip 91.240.243.18
  582. 2022-06-29 11:25:17.329698 97.77% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 62.197.148.4
  583. 2022-06-29 11:25:17.509693 97.77% [WARNING] sofia_reg.c:3223 Can't find user [769@102.220.200.133] from 62.197.148.4
  584. You must define a domain called '102.220.200.133' in your directory and add a user with the id="769" attribute
  585. and you must configure your device to use the proper domain in its authentication credentials.
  586. 2022-06-29 11:25:17.509693 97.77% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 62.197.148.4
  587. 2022-06-29 11:25:36.489691 98.97% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [690@102.220.200.133] from ip 62.197.144.11
  588. 2022-06-29 11:25:36.709659 99.17% [WARNING] sofia_reg.c:3223 Can't find user [690@102.220.200.133] from 62.197.144.11
  589. You must define a domain called '102.220.200.133' in your directory and add a user with the id="690" attribute
  590. and you must configure your device to use the proper domain in its authentication credentials.
  591. 2022-06-29 11:25:36.709659 99.17% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [690@102.220.200.133] from ip 62.197.144.11
  592. 2022-06-29 11:26:01.789673 98.97% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [742@102.220.200.133] from ip 45.129.32.39
  593. 2022-06-29 11:26:02.349691 98.97% [WARNING] sofia_reg.c:3223 Can't find user [742@102.220.200.133] from 45.129.32.39
  594. You must define a domain called '102.220.200.133' in your directory and add a user with the id="742" attribute
  595. and you must configure your device to use the proper domain in its authentication credentials.
  596. 2022-06-29 11:26:02.349691 98.97% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [742@102.220.200.133] from ip 45.129.32.39
  597. 2022-06-29 11:26:39.169698 99.13% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [669@102.220.200.133] from ip 146.70.102.190
  598. 2022-06-29 11:26:39.709693 99.17% [WARNING] sofia_reg.c:3223 Can't find user [669@102.220.200.133] from 146.70.102.190
  599. You must define a domain called '102.220.200.133' in your directory and add a user with the id="669" attribute
  600. and you must configure your device to use the proper domain in its authentication credentials.
  601. 2022-06-29 11:26:39.709693 99.17% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [669@102.220.200.133] from ip 146.70.102.190
  602. 2022-06-29 11:26:40.249694 99.17% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [762@102.220.200.133] from ip 194.169.170.4
  603. 2022-06-29 11:26:40.749693 99.17% [WARNING] sofia_reg.c:3223 Can't find user [762@102.220.200.133] from 194.169.170.4
  604. You must define a domain called '102.220.200.133' in your directory and add a user with the id="762" attribute
  605. and you must configure your device to use the proper domain in its authentication credentials.
  606. 2022-06-29 11:26:40.749693 99.17% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [762@102.220.200.133] from ip 194.169.170.4
  607. 2022-06-29 11:26:50.429651 99.10% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [770@102.220.200.133] from ip 212.102.40.87
  608. 2022-06-29 11:26:55.769694 98.97% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [691@102.220.200.133] from ip 212.102.48.16
  609. 2022-06-29 11:26:56.009694 98.97% [WARNING] sofia_reg.c:3223 Can't find user [691@102.220.200.133] from 212.102.48.16
  610. You must define a domain called '102.220.200.133' in your directory and add a user with the id="691" attribute
  611. and you must configure your device to use the proper domain in its authentication credentials.
  612. 2022-06-29 11:26:56.009694 98.97% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [691@102.220.200.133] from ip 212.102.48.16
  613. 2022-06-29 11:27:03.829695 98.20% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 62.197.156.4
  614. 2022-06-29 11:27:04.449690 98.20% [WARNING] sofia_reg.c:3223 Can't find user [769@102.220.200.133] from 62.197.156.4
  615. You must define a domain called '102.220.200.133' in your directory and add a user with the id="769" attribute
  616. and you must configure your device to use the proper domain in its authentication credentials.
  617. 2022-06-29 11:27:04.449690 98.20% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 62.197.156.4
  618. 2022-06-29 11:27:05.269694 98.17% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [576@102.220.200.133] from ip 45.136.155.49
  619. 2022-06-29 11:27:05.489656 98.17% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [767@102.220.200.133] from ip 45.136.155.56
  620. 2022-06-29 11:27:05.729694 98.20% [WARNING] sofia_reg.c:3223 Can't find user [576@102.220.200.133] from 45.136.155.49
  621. You must define a domain called '102.220.200.133' in your directory and add a user with the id="576" attribute
  622. and you must configure your device to use the proper domain in its authentication credentials.
  623. 2022-06-29 11:27:05.729694 98.20% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [576@102.220.200.133] from ip 45.136.155.49
  624. 2022-06-29 11:27:05.909683 98.20% [WARNING] sofia_reg.c:3223 Can't find user [767@102.220.200.133] from 45.136.155.56
  625. You must define a domain called '102.220.200.133' in your directory and add a user with the id="767" attribute
  626. and you must configure your device to use the proper domain in its authentication credentials.
  627. 2022-06-29 11:27:05.909683 98.20% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [767@102.220.200.133] from ip 45.136.155.56
  628. 2022-06-29 11:27:11.769703 98.07% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [6688@102.220.200.133] from ip 85.14.245.202
  629. 2022-06-29 11:27:16.669697 98.03% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [691@102.220.200.133] from ip 45.43.19.83
  630. 2022-06-29 11:27:17.009693 98.03% [WARNING] sofia_reg.c:3223 Can't find user [691@102.220.200.133] from 45.43.19.83
  631. You must define a domain called '102.220.200.133' in your directory and add a user with the id="691" attribute
  632. and you must configure your device to use the proper domain in its authentication credentials.
  633. 2022-06-29 11:27:17.009693 98.03% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [691@102.220.200.133] from ip 45.43.19.83
  634. 2022-06-29 11:27:29.229693 98.33% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [684@102.220.200.133] from ip 89.187.163.193
  635. 2022-06-29 11:27:29.909701 98.33% [WARNING] sofia_reg.c:3223 Can't find user [684@102.220.200.133] from 89.187.163.193
  636. You must define a domain called '102.220.200.133' in your directory and add a user with the id="684" attribute
  637. and you must configure your device to use the proper domain in its authentication credentials.
  638. 2022-06-29 11:27:29.909701 98.33% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [684@102.220.200.133] from ip 89.187.163.193
  639. 2022-06-29 11:27:53.689695 99.33% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [770@102.220.200.133] from ip 45.136.155.91
  640. 2022-06-29 11:27:53.929694 99.33% [WARNING] sofia_reg.c:3223 Can't find user [770@102.220.200.133] from 45.136.155.91
  641. You must define a domain called '102.220.200.133' in your directory and add a user with the id="770" attribute
  642. and you must configure your device to use the proper domain in its authentication credentials.
  643. 2022-06-29 11:27:53.929694 99.33% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [770@102.220.200.133] from ip 45.136.155.91
  644. 2022-06-29 11:28:01.469694 99.07% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 85.204.124.94
  645. 2022-06-29 11:28:01.889630 98.97% [WARNING] sofia_reg.c:3223 Can't find user [769@102.220.200.133] from 85.204.124.94
  646. You must define a domain called '102.220.200.133' in your directory and add a user with the id="769" attribute
  647. and you must configure your device to use the proper domain in its authentication credentials.
  648. 2022-06-29 11:28:01.889630 98.97% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 85.204.124.94
  649. 2022-06-29 11:28:10.609699 98.10% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [767@102.220.200.133] from ip 45.134.224.25
  650. 2022-06-29 11:28:11.189690 98.13% [WARNING] sofia_reg.c:3223 Can't find user [767@102.220.200.133] from 45.134.224.25
  651. You must define a domain called '102.220.200.133' in your directory and add a user with the id="767" attribute
  652. and you must configure your device to use the proper domain in its authentication credentials.
  653. 2022-06-29 11:28:11.189690 98.13% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [767@102.220.200.133] from ip 45.134.224.25
  654. 2022-06-29 11:28:17.529700 98.10% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [770@102.220.200.133] from ip 62.197.148.11
  655. 2022-06-29 11:28:17.809694 98.10% [WARNING] sofia_reg.c:3223 Can't find user [770@102.220.200.133] from 62.197.148.11
  656. You must define a domain called '102.220.200.133' in your directory and add a user with the id="770" attribute
  657. and you must configure your device to use the proper domain in its authentication credentials.
  658. 2022-06-29 11:28:17.809694 98.10% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [770@102.220.200.133] from ip 62.197.148.11
  659. 2022-06-29 11:28:18.609693 98.10% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [691@102.220.200.133] from ip 143.244.46.216
  660. 2022-06-29 11:28:18.829699 98.10% [WARNING] sofia_reg.c:3223 Can't find user [691@102.220.200.133] from 143.244.46.216
  661. You must define a domain called '102.220.200.133' in your directory and add a user with the id="691" attribute
  662. and you must configure your device to use the proper domain in its authentication credentials.
  663. 2022-06-29 11:28:18.829699 98.10% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [691@102.220.200.133] from ip 143.244.46.216
  664. 2022-06-29 11:29:07.749678 98.67% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [654@102.220.200.133] from ip 92.62.120.6
  665. 2022-06-29 11:29:07.949697 98.67% [WARNING] sofia_reg.c:3223 Can't find user [654@102.220.200.133] from 92.62.120.6
  666. You must define a domain called '102.220.200.133' in your directory and add a user with the id="654" attribute
  667. and you must configure your device to use the proper domain in its authentication credentials.
  668. 2022-06-29 11:29:07.949697 98.67% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [654@102.220.200.133] from ip 92.62.120.6
  669. 2022-06-29 11:29:14.069699 98.63% [NOTICE] switch_channel.c:1123 New Channel sofia/default/3100102220200133@102.220.200.133 [016c9e35-f35c-40b0-9735-e08cdbb5ff77]
  670. 2022-06-29 11:29:14.069699 98.63% [DEBUG] switch_core_state_machine.c:581 (sofia/default/3100102220200133@102.220.200.133) Running State Change CS_NEW (Cur 1 Tot 705)
  671. 2022-06-29 11:29:14.069699 98.63% [INFO] sofia.c:10462 sofia/default/3100102220200133@102.220.200.133 receiving invite from 89.163.241.34:62465 version: 1.10.7 -release-19-883d2cb662 64bit call-id: 817916956-1907052724-425026322
  672. 2022-06-29 11:29:14.069699 98.63% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 89.163.241.34:0.
  673. 2022-06-29 11:29:14.069699 98.63% [WARNING] sofia_reg.c:1861 SIP auth challenge (INVITE) on sofia profile 'default' for [3100972595725668@102.220.200.133] from ip 89.163.241.34
  674. 2022-06-29 11:29:14.069699 98.63% [DEBUG] switch_core_state_machine.c:600 (sofia/default/3100102220200133@102.220.200.133) State NEW
  675. 2022-06-29 11:29:14.069699 98.63% [DEBUG] sofia.c:2419 detaching session 016c9e35-f35c-40b0-9735-e08cdbb5ff77
  676. 2022-06-29 11:29:24.109690 98.63% [WARNING] switch_core_state_machine.c:684 016c9e35-f35c-40b0-9735-e08cdbb5ff77 sofia/default/3100102220200133@102.220.200.133 Abandoned
  677. 2022-06-29 11:29:24.109690 98.63% [NOTICE] switch_core_state_machine.c:687 Hangup sofia/default/3100102220200133@102.220.200.133 [CS_NEW] [WRONG_CALL_STATE]
  678. 2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:581 (sofia/default/3100102220200133@102.220.200.133) Running State Change CS_HANGUP (Cur 1 Tot 705)
  679. 2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:844 (sofia/default/3100102220200133@102.220.200.133) Callstate Change DOWN -> HANGUP
  680. 2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:846 (sofia/default/3100102220200133@102.220.200.133) State HANGUP
  681. 2022-06-29 11:29:24.109690 98.63% [DEBUG] mod_sofia.c:468 Channel sofia/default/3100102220200133@102.220.200.133 hanging up, cause: WRONG_CALL_STATE
  682. 2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:59 sofia/default/3100102220200133@102.220.200.133 Standard HANGUP, cause: WRONG_CALL_STATE
  683. 2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:846 (sofia/default/3100102220200133@102.220.200.133) State HANGUP going to sleep
  684. 2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:616 (sofia/default/3100102220200133@102.220.200.133) State Change CS_HANGUP -> CS_REPORTING
  685. 2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:581 (sofia/default/3100102220200133@102.220.200.133) Running State Change CS_REPORTING (Cur 1 Tot 705)
  686. 2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:932 (sofia/default/3100102220200133@102.220.200.133) State REPORTING
  687. 2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:168 sofia/default/3100102220200133@102.220.200.133 Standard REPORTING, cause: WRONG_CALL_STATE
  688. 2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:932 (sofia/default/3100102220200133@102.220.200.133) State REPORTING going to sleep
  689. 2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:607 (sofia/default/3100102220200133@102.220.200.133) State Change CS_REPORTING -> CS_DESTROY
  690. 2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_session.c:1753 Session 705 (sofia/default/3100102220200133@102.220.200.133) Locked, Waiting on external entities
  691. 2022-06-29 11:29:24.109690 98.63% [NOTICE] switch_core_session.c:1771 Session 705 (sofia/default/3100102220200133@102.220.200.133) Ended
  692. 2022-06-29 11:29:24.109690 98.63% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/3100102220200133@102.220.200.133 [CS_DESTROY]
  693. 2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:735 (sofia/default/3100102220200133@102.220.200.133) Running State Change CS_DESTROY (Cur 0 Tot 705)
  694. 2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:745 (sofia/default/3100102220200133@102.220.200.133) State DESTROY
  695. 2022-06-29 11:29:24.109690 98.63% [DEBUG] mod_sofia.c:379 sofia/default/3100102220200133@102.220.200.133 SOFIA DESTROY
  696. 2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:175 sofia/default/3100102220200133@102.220.200.133 Standard DESTROY
  697. 2022-06-29 11:29:24.109690 98.63% [DEBUG] switch_core_state_machine.c:745 (sofia/default/3100102220200133@102.220.200.133) State DESTROY going to sleep
  698. 2022-06-29 11:29:33.209693 99.17% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [677@102.220.200.133] from ip 62.197.144.9
  699. 2022-06-29 11:29:33.569693 99.17% [WARNING] sofia_reg.c:3223 Can't find user [677@102.220.200.133] from 62.197.144.9
  700. You must define a domain called '102.220.200.133' in your directory and add a user with the id="677" attribute
  701. and you must configure your device to use the proper domain in its authentication credentials.
  702. 2022-06-29 11:29:33.569693 99.17% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [677@102.220.200.133] from ip 62.197.144.9
  703. 2022-06-29 11:29:38.409698 99.13% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [688@102.220.200.133] from ip 193.218.35.13
  704. 2022-06-29 11:29:38.989644 99.13% [WARNING] sofia_reg.c:3223 Can't find user [688@102.220.200.133] from 193.218.35.13
  705. You must define a domain called '102.220.200.133' in your directory and add a user with the id="688" attribute
  706. and you must configure your device to use the proper domain in its authentication credentials.
  707. 2022-06-29 11:29:38.989644 99.13% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [688@102.220.200.133] from ip 193.218.35.13
  708. 2022-06-29 11:29:41.949662 99.17% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [767@102.220.200.133] from ip 62.197.152.9
  709. 2022-06-29 11:29:42.349694 99.17% [WARNING] sofia_reg.c:3223 Can't find user [767@102.220.200.133] from 62.197.152.9
  710. You must define a domain called '102.220.200.133' in your directory and add a user with the id="767" attribute
  711. and you must configure your device to use the proper domain in its authentication credentials.
  712. 2022-06-29 11:29:42.349694 99.17% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [767@102.220.200.133] from ip 62.197.152.9
  713. 2022-06-29 11:29:56.669692 98.97% [NOTICE] switch_channel.c:1123 New Channel sofia/default/0902@102.220.200.133 [c71261ca-c074-4061-a372-aa03d5185441]
  714. 2022-06-29 11:29:56.669692 98.97% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_NEW (Cur 1 Tot 706)
  715. 2022-06-29 11:29:56.669692 98.97% [INFO] sofia.c:10462 sofia/default/0902@102.220.200.133 receiving invite from 102.220.201.145:5060 version: 1.10.7 -release-19-883d2cb662 64bit call-id: bf2d6da2-79684487@102.220.201.145
  716. 2022-06-29 11:29:56.669692 98.97% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 102.220.201.145:0.
  717. 2022-06-29 11:29:56.669692 98.97% [WARNING] sofia_reg.c:1861 SIP auth challenge (INVITE) on sofia profile 'default' for [0000@102.220.200.133] from ip 102.220.201.145
  718. 2022-06-29 11:29:56.669692 98.97% [DEBUG] switch_core_state_machine.c:600 (sofia/default/0902@102.220.200.133) State NEW
  719. 2022-06-29 11:29:56.669692 98.97% [DEBUG] sofia.c:2419 detaching session c71261ca-c074-4061-a372-aa03d5185441
  720. 2022-06-29 11:29:56.689693 98.97% [DEBUG] sofia.c:2532 Re-attaching to session c71261ca-c074-4061-a372-aa03d5185441
  721. 2022-06-29 11:29:56.689693 98.97% [INFO] sofia.c:10462 sofia/default/0902@102.220.200.133 receiving invite from 102.220.201.145:5060 version: 1.10.7 -release-19-883d2cb662 64bit call-id: bf2d6da2-79684487@102.220.201.145
  722. 2022-06-29 11:29:56.689693 98.97% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 102.220.201.145:0.
  723. 2022-06-29 11:29:56.709636 98.97% [DEBUG] sofia.c:7499 Channel sofia/default/0902@102.220.200.133 entering state [received][100]
  724. 2022-06-29 11:29:56.709636 98.97% [DEBUG] sofia.c:7509 Remote SDP:
  725. v=0
  726. o=- 14906178 14906178 IN IP4 102.220.201.145
  727. s=-
  728. c=IN IP4 102.220.201.145
  729. t=0 0
  730. m=audio 16538 RTP/AVP 0 2 8 9 18 96 97 98 101
  731. a=rtpmap:0 PCMU/8000
  732. a=rtpmap:2 G726-32/8000
  733. a=rtpmap:8 PCMA/8000
  734. a=rtpmap:9 G722/8000
  735. a=rtpmap:18 G729a/8000
  736. a=rtpmap:96 G726-40/8000
  737. a=rtpmap:97 G726-24/8000
  738. a=rtpmap:98 G726-16/8000
  739. a=rtpmap:101 telephone-event/8000
  740. a=fmtp:101 0-15
  741. a=ptime:30
  742.  
  743. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:30:64000:1]/[PCMA:8:8000:20:64000:1]
  744. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:30:64000:1]/[PCMU:0:8000:20:64000:1]
  745. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5686 Audio Codec Compare [PCMU:0:8000:20:64000:1] is saved as a near-match
  746. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-32:2:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
  747. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-32:2:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
  748. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:30:64000:1]/[PCMA:8:8000:20:64000:1]
  749. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5686 Audio Codec Compare [PCMA:8:8000:20:64000:1] is saved as a near-match
  750. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:30:64000:1]/[PCMU:0:8000:20:64000:1]
  751. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G722:9:8000:30:64000:1]/[PCMA:8:8000:20:64000:1]
  752. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G722:9:8000:30:64000:1]/[PCMU:0:8000:20:64000:1]
  753. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729a:18:8000:30:8000:1]/[PCMA:8:8000:20:64000:1]
  754. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729a:18:8000:30:8000:1]/[PCMU:0:8000:20:64000:1]
  755. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-40:96:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
  756. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-40:96:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
  757. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-24:97:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
  758. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-24:97:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
  759. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-16:98:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
  760. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-16:98:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
  761. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5566 Set telephone-event payload to 101@8000
  762. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5757 Substituting codec PCMU@30i@8000h@1c
  763. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:3870 Set Codec sofia/default/0902@102.220.200.133 PCMU/8000 30 ms 240 samples 64000 bits 1 channels
  764. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_codec.c:111 sofia/default/0902@102.220.200.133 Original read codec set to PCMU:0
  765. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5915 Set telephone-event payload to 101@8000
  766. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:5973 sofia/default/0902@102.220.200.133 Set 2833 dtmf send payload to 101 recv payload to 101
  767. 2022-06-29 11:29:56.709636 98.97% [DEBUG] sofia.c:7933 (sofia/default/0902@102.220.200.133) State Change CS_NEW -> CS_INIT
  768. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_INIT (Cur 1 Tot 706)
  769. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_state_machine.c:624 (sofia/default/0902@102.220.200.133) State INIT
  770. 2022-06-29 11:29:56.709636 98.97% [DEBUG] mod_sofia.c:97 sofia/default/0902@102.220.200.133 SOFIA INIT
  771. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_state_machine.c:40 sofia/default/0902@102.220.200.133 Standard INIT
  772. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_state_machine.c:48 (sofia/default/0902@102.220.200.133) State Change CS_INIT -> CS_ROUTING
  773. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_state_machine.c:624 (sofia/default/0902@102.220.200.133) State INIT going to sleep
  774. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_ROUTING (Cur 1 Tot 706)
  775. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_channel.c:2380 (sofia/default/0902@102.220.200.133) Callstate Change DOWN -> RINGING
  776. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_state_machine.c:640 (sofia/default/0902@102.220.200.133) State ROUTING
  777. 2022-06-29 11:29:56.709636 98.97% [DEBUG] mod_sofia.c:158 sofia/default/0902@102.220.200.133 SOFIA ROUTING
  778. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_state_machine.c:230 sofia/default/0902@102.220.200.133 Standard ROUTING
  779. 2022-06-29 11:29:56.709636 98.97% [INFO] mod_dialplan_xml.c:639 Processing 0902 <0902>->0000 in context default
  780. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes')
  781. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
  782. 2022-06-29 11:29:56.709636 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] Dialed number : 0000
  783. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT access_number FROM accessnumber WHERE access_number = '0000' AND status=0 limit 1
  784. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Generated XML:
  785. <?xml version="1.0" encoding="UTF-8" standalone="no"?>
  786. <document type="freeswitch/xml">
  787. <section name="dialplan" description="ASTPP Dialplan">
  788. <context name="default">
  789. <extension name="0000">
  790. <condition field="destination_number" expression="0000">
  791. <action application="log" data="INFO ASTPP - Calling Card Call"/>
  792. <action application="answer"/>
  793. <action application="sleep" data="2000"/>
  794. <action application="lua" data="astpp-callingcards.lua"/>
  795. </condition>
  796. </extension>
  797. </context>
  798. </section>
  799. </document>
  800. Dialplan: sofia/default/0902@102.220.200.133 parsing [default->0000] continue=false
  801. Dialplan: sofia/default/0902@102.220.200.133 Regex (PASS) [0000] destination_number(0000) =~ /0000/ break=on-false
  802. Dialplan: sofia/default/0902@102.220.200.133 Action log(INFO ASTPP - Calling Card Call)
  803. Dialplan: sofia/default/0902@102.220.200.133 Action answer()
  804. Dialplan: sofia/default/0902@102.220.200.133 Action sleep(2000)
  805. Dialplan: sofia/default/0902@102.220.200.133 Action lua(astpp-callingcards.lua)
  806. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_state_machine.c:281 (sofia/default/0902@102.220.200.133) State Change CS_ROUTING -> CS_EXECUTE
  807. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_state_machine.c:640 (sofia/default/0902@102.220.200.133) State ROUTING going to sleep
  808. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_EXECUTE (Cur 1 Tot 706)
  809. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_state_machine.c:647 (sofia/default/0902@102.220.200.133) State EXECUTE
  810. 2022-06-29 11:29:56.709636 98.97% [DEBUG] mod_sofia.c:213 sofia/default/0902@102.220.200.133 SOFIA EXECUTE
  811. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_state_machine.c:323 sofia/default/0902@102.220.200.133 Standard EXECUTE
  812. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 log(INFO ASTPP - Calling Card Call)
  813. 2022-06-29 11:29:56.709636 98.97% [INFO] mod_dptools.c:1879 ASTPP - Calling Card Call
  814. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 answer()
  815. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:8777 AUDIO RTP [sofia/default/0902@102.220.200.133] 102.220.200.133 port 26588 -> 102.220.201.145 port 16538 codec: 0 ms: 30
  816. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_rtp.c:4619 Starting timer [soft] 240 bytes per 30ms
  817. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:9089 sofia/default/0902@102.220.200.133 Set 2833 dtmf send payload to 101
  818. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:9096 sofia/default/0902@102.220.200.133 Set 2833 dtmf receive payload to 101
  819. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_core_media.c:9119 sofia/default/0902@102.220.200.133 Set rtp dtmf delay to 40
  820. 2022-06-29 11:29:56.709636 98.97% [DEBUG] mod_sofia.c:913 Local SDP sofia/default/0902@102.220.200.133:
  821. v=0
  822. o=FreeSWITCH 1656464808 1656464809 IN IP4 102.220.200.133
  823. s=FreeSWITCH
  824. c=IN IP4 102.220.200.133
  825. t=0 0
  826. m=audio 26588 RTP/AVP 0 101
  827. a=rtpmap:0 PCMU/8000
  828. a=rtpmap:101 telephone-event/8000
  829. a=fmtp:101 0-15
  830. a=ptime:30
  831. a=sendrecv
  832.  
  833. 2022-06-29 11:29:56.709636 98.97% [NOTICE] mod_dptools.c:1419 Channel [sofia/default/0902@102.220.200.133] has been answered
  834. 2022-06-29 11:29:56.709636 98.97% [DEBUG] switch_channel.c:3950 (sofia/default/0902@102.220.200.133) Callstate Change RINGING -> ACTIVE
  835. 2022-06-29 11:29:56.709636 98.97% [DEBUG] sofia.c:7499 Channel sofia/default/0902@102.220.200.133 entering state [completed][200]
  836. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 sleep(2000)
  837. 2022-06-29 11:29:56.769690 98.97% [DEBUG] sofia.c:7499 Channel sofia/default/0902@102.220.200.133 entering state [ready][200]
  838. 2022-06-29 11:29:56.809690 98.97% [DEBUG] switch_rtp.c:7934 Correct audio ip/port confirmed.
  839. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 lua(astpp-callingcards.lua)
  840. 2022-06-29 11:29:58.729695 98.93% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes')
  841. 2022-06-29 11:29:58.729695 98.93% [NOTICE] switch_cpp.cpp:1465 [ASTPP] SECTION
  842. 2022-06-29 11:29:58.749615 98.93% [DEBUG] switch_core_file.c:444 File /var/www/html/astpp/upload/astpp-welcome.wav sample rate 16000 doesn't match requested rate 8000
  843. 2022-06-29 11:29:58.749615 98.93% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  844. 2022-06-29 11:30:00.529694 98.93% [DEBUG] switch_ivr_play_say.c:2001 done playing file /var/www/html/astpp/upload/astpp-welcome.wav
  845. 2022-06-29 11:30:00.529694 98.93% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-accountnum.wav sample rate 16000 doesn't match requested rate 8000
  846. 2022-06-29 11:30:00.529694 98.93% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  847. 2022-06-29 11:30:03.529689 98.33% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-accountnum.wav
  848. 2022-06-29 11:30:03.949694 98.23% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:1200
  849. 2022-06-29 11:30:03.949694 98.23% [INFO] switch_channel.c:527 RECV DTMF 1:1200
  850. 2022-06-29 11:30:04.309699 98.23% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 2:800
  851. 2022-06-29 11:30:04.309699 98.23% [INFO] switch_channel.c:527 RECV DTMF 2:800
  852. 2022-06-29 11:30:04.749690 98.23% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:1136
  853. 2022-06-29 11:30:04.749690 98.23% [INFO] switch_channel.c:527 RECV DTMF 7:1136
  854. 2022-06-29 11:30:05.049646 98.23% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:1296
  855. 2022-06-29 11:30:05.049646 98.23% [INFO] switch_channel.c:527 RECV DTMF 7:1296
  856. 2022-06-29 11:30:05.469695 98.23% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:1536
  857. 2022-06-29 11:30:05.469695 98.23% [INFO] switch_channel.c:527 RECV DTMF 1:1536
  858. 2022-06-29 11:30:05.949669 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 8:1200
  859. 2022-06-29 11:30:05.949669 98.07% [INFO] switch_channel.c:527 RECV DTMF 8:1200
  860. 2022-06-29 11:30:06.349646 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF #:1200
  861. span style="color: green; font-weight: bold;"> 2022-06-29 11:30:06.349646 98.07% [INFO] switch_channel.c:527 RECV DTMF #:1200
  862. span style="color: goldenrod; font-weight: bold;"> 2022-06-29 11:30:06.349646 98.07% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Got DTMF digits: 127718
  863. 2022-06-29 11:30:06.349646 98.07% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT *,(select currencyrate from currency where id=currency_id) as currencyrate FROM accounts WHERE number = "127718" AND status=0 AND deleted=0 limit 1
  864. 2022-06-29 11:30:06.349646 98.07% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-pleasepin.wav sample rate 16000 doesn't match requested rate 8000
  865. 2022-06-29 11:30:06.349646 98.07% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  866. 2022-06-29 11:30:09.009648 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 6:1280
  867. 2022-06-29 11:30:09.009648 98.07% [INFO] switch_channel.c:527 RECV DTMF 6:1280
  868. 2022-06-29 11:30:09.009648 98.07% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-pleasepin.wav
  869. 2022-06-29 11:30:09.369694 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 3:896
  870. 2022-06-29 11:30:09.369694 98.07% [INFO] switch_channel.c:527 RECV DTMF 3:896
  871. 2022-06-29 11:30:09.829700 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:960
  872. 2022-06-29 11:30:09.829700 98.07% [INFO] switch_channel.c:527 RECV DTMF 1:960
  873. 2022-06-29 11:30:10.149694 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 4:960
  874. 2022-06-29 11:30:10.149694 98.07% [INFO] switch_channel.c:527 RECV DTMF 4:960
  875. 2022-06-29 11:30:10.629699 98.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF #:1456
  876. span style="color: green; font-weight: bold;"> 2022-06-29 11:30:10.629699 98.07% [INFO] switch_channel.c:527 RECV DTMF #:1456
  877. span style="color: goldenrod; font-weight: bold;"> 2022-06-29 11:30:10.629699 98.07% [DEBUG] switch_cpp.cpp:1465 [ASTPP] We recieved a pin : 6314
  878. 2022-06-29 11:30:10.629699 98.07% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [validate_card_usage] Query :SELECT DATE_FORMAT('2032-06-21 10:11:08' , '%Y%m%d%H%i%s') AS expiry
  879. 2022-06-29 11:30:10.629699 98.07% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [validate_card_usage] Query :SELECT DATE_FORMAT('2022-06-29 08:30:10' , '%Y%m%d%H%i%s') AS expiry
  880. 2022-06-29 11:30:10.649624 98.03% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [Accountcode : 127718]
  881. 2022-06-29 11:30:10.649624 98.03% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-this-card-has-a-balance-of.wav sample rate 16000 doesn't match requested rate 8000
  882. 2022-06-29 11:30:10.649624 98.03% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  883. 2022-06-29 11:30:11.949699 98.03% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-this-card-has-a-balance-of.wav
  884. 2022-06-29 11:30:11.949699 98.03% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [Play Amount First Part] Query :5000
  885. 2022-06-29 11:30:11.949699 98.03% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [Play Amount Second Part] Query :00
  886. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 say(en number pronounced 5000)
  887. 2022-06-29 11:30:11.969630 98.03% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  888. 2022-06-29 11:30:13.189699 97.93% [DEBUG] switch_ivr_play_say.c:2001 done playing file file_string://digits/5.wav!digits/thousand.wav
  889. 2022-06-29 11:30:13.189699 97.93% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-point.wav sample rate 16000 doesn't match requested rate 8000
  890. 2022-06-29 11:30:13.189699 97.93% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  891. 2022-06-29 11:30:13.749697 97.93% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-point.wav
  892. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 say(en number pronounced 00)
  893. 2022-06-29 11:30:13.789625 97.93% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  894. 2022-06-29 11:30:14.529690 97.93% [DEBUG] switch_ivr_play_say.c:2001 done playing file file_string://digits/0.wav
  895. 2022-06-29 11:30:14.549632 97.93% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-phonenum.wav sample rate 16000 doesn't match requested rate 8000
  896. 2022-06-29 11:30:14.549632 97.93% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  897. 2022-06-29 11:30:18.249691 97.93% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-phonenum.wav
  898. 2022-06-29 11:30:30.229699 98.17% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [690@102.220.200.133] from ip 156.146.45.104
  899. 2022-06-29 11:30:30.909694 98.17% [WARNING] sofia_reg.c:3223 Can't find user [690@102.220.200.133] from 156.146.45.104
  900. You must define a domain called '102.220.200.133' in your directory and add a user with the id="690" attribute
  901. and you must configure your device to use the proper domain in its authentication credentials.
  902. 2022-06-29 11:30:30.909694 98.17% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [690@102.220.200.133] from ip 156.146.45.104
  903. 2022-06-29 11:30:33.309650 98.73% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-badphone.wav sample rate 16000 doesn't match requested rate 8000
  904. 2022-06-29 11:30:33.309650 98.73% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  905. 2022-06-29 11:30:34.729698 98.87% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-badphone.wav
  906. 2022-06-29 11:30:34.729698 98.87% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-phonenum.wav sample rate 16000 doesn't match requested rate 8000
  907. 2022-06-29 11:30:34.729698 98.87% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  908. 2022-06-29 11:30:37.029694 99.10% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 9:1184
  909. 2022-06-29 11:30:37.029694 99.10% [INFO] switch_channel.c:527 RECV DTMF 9:1184
  910. 2022-06-29 11:30:37.029694 99.10% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-phonenum.wav
  911. 2022-06-29 11:30:37.449690 99.10% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 0:1280
  912. 2022-06-29 11:30:37.449690 99.10% [INFO] switch_channel.c:527 RECV DTMF 0:1280
  913. 2022-06-29 11:30:37.749690 99.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:624
  914. 2022-06-29 11:30:37.749690 99.07% [INFO] switch_channel.c:527 RECV DTMF 7:624
  915. 2022-06-29 11:30:37.989694 99.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:640
  916. 2022-06-29 11:30:37.989694 99.07% [INFO] switch_channel.c:527 RECV DTMF 7:640
  917. 2022-06-29 11:30:38.329695 99.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 9:960
  918. 2022-06-29 11:30:38.329695 99.07% [INFO] switch_channel.c:527 RECV DTMF 9:960
  919. 2022-06-29 11:30:38.709699 99.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 2:1184
  920. 2022-06-29 11:30:38.709699 99.07% [INFO] switch_channel.c:527 RECV DTMF 2:1184
  921. 2022-06-29 11:30:39.129695 99.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 0:1440
  922. 2022-06-29 11:30:39.129695 99.07% [INFO] switch_channel.c:527 RECV DTMF 0:1440
  923. 2022-06-29 11:30:39.429699 99.07% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 5:960
  924. 2022-06-29 11:30:39.429699 99.07% [INFO] switch_channel.c:527 RECV DTMF 5:960
  925. 2022-06-29 11:30:39.569690 99.07% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [673@102.220.200.133] from ip 93.190.138.235
  926. 2022-06-29 11:30:39.809691 98.97% [WARNING] sofia_reg.c:3223 Can't find user [673@102.220.200.133] from 93.190.138.235
  927. You must define a domain called '102.220.200.133' in your directory and add a user with the id="673" attribute
  928. and you must configure your device to use the proper domain in its authentication credentials.
  929. 2022-06-29 11:30:39.809691 98.97% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [673@102.220.200.133] from ip 93.190.138.235
  930. 2022-06-29 11:30:39.829627 98.97% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 0:1120
  931. 2022-06-29 11:30:39.829627 98.97% [INFO] switch_channel.c:527 RECV DTMF 0:1120
  932. 2022-06-29 11:30:40.189691 98.97% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 9:1120
  933. 2022-06-29 11:30:40.189691 98.97% [INFO] switch_channel.c:527 RECV DTMF 9:1120
  934. 2022-06-29 11:30:40.549694 98.97% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:1200
  935. 2022-06-29 11:30:40.549694 98.97% [INFO] switch_channel.c:527 RECV DTMF 7:1200
  936. 2022-06-29 11:30:40.929695 98.97% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF #:1360
  937. span style="color: green; font-weight: bold;"> 2022-06-29 11:30:40.929695 98.97% [INFO] switch_channel.c:527 RECV DTMF #:1360
  938. span style="color: green; font-weight: bold;"> 2022-06-29 11:30:40.929695 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] [CHECK_destination] Dialed destination number :90779205097
  939. 2022-06-29 11:30:40.929695 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Account Information ===================
  940. 2022-06-29 11:30:40.929695 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] User id : 17
  941. 2022-06-29 11:30:40.929695 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] Account code : 127718
  942. 2022-06-29 11:30:40.929695 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] Balance : 5000
  943. 2022-06-29 11:30:40.929695 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] Type : 0 [0:prepaid,1:postpaid]
  944. 2022-06-29 11:30:40.929695 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] Ratecard id : 4
  945. 2022-06-29 11:30:40.929695 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] ========================================================
  946. 2022-06-29 11:30:40.929695 98.97% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CHECK_BLOCKED_PREFIX] Query :SELECT * FROM block_patterns WHERE (blocked_patterns = '^90779205097.*' OR blocked_patterns = '^9077920509.*' OR blocked_patterns = '^907792050.*' OR blocked_patterns = '^90779205.*' OR blocked_patterns = '^9077920.*' OR blocked_patterns = '^907792.*' OR blocked_patterns = '^90779.*' OR blocked_patterns = '^9077.*' OR blocked_patterns = '^907.*' OR blocked_patterns = '^90.*' OR blocked_patterns = '^9.*' OR blocked_patterns ='--') AND accountid = 17 limit 1
  947. 2022-06-29 11:30:40.949626 98.97% [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 (patterns = '^90779205097.*' OR patterns = '^9077920509.*' OR patterns = '^907792050.*' OR patterns = '^90779205.*' OR patterns = '^9077920.*' OR patterns = '^907792.*' OR patterns = '^90779.*' OR patterns = '^9077.*' OR patterns = '^907.*' OR patterns = '^90.*' OR patterns = '^9.*' OR patterns ='--') AND accountid = 17 ORDER BY LENGTH(PKGPTR.patterns) DESC
  948. 2022-06-29 11:30:40.949626 98.97% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 4 AND status = 0
  949. 2022-06-29 11:30:40.949626 98.97% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_RATES] call_direction :
  950. 2022-06-29 11:30:40.949626 98.97% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_RATES] Query :SELECT * FROM routes WHERE (pattern = '^90779205097.*' OR pattern = '^9077920509.*' OR pattern = '^907792050.*' OR pattern = '^90779205.*' OR pattern = '^9077920.*' OR pattern = '^907792.*' OR pattern = '^90779.*' OR pattern = '^9077.*' OR pattern = '^907.*' OR pattern = '^90.*' OR pattern = '^9.*' OR pattern ='--') AND status = 0 AND (pricelist_id = 4 OR accountid=17)  ORDER BY accountid DESC,LENGTH(pattern) DESC,cost DESC LIMIT 1
  951. 2022-06-29 11:30:40.949626 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] call_direction::::::
  952. 2022-06-29 11:30:40.949626 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Rates Information ===================
  953. 2022-06-29 11:30:40.949626 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] ID : 8
  954. 2022-06-29 11:30:40.949626 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] Connectcost : 0.00000
  955. 2022-06-29 11:30:40.949626 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] Includedseconds : 0
  956. 2022-06-29 11:30:40.949626 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] Cost : 220.00000
  957. 2022-06-29 11:30:40.949626 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] comment : Uganda
  958. 2022-06-29 11:30:40.949626 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] Country Id : 197
  959. 2022-06-29 11:30:40.949626 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] Accid : 17
  960. 2022-06-29 11:30:40.949626 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] Trunk ID: 3
  961. 2022-06-29 11:30:40.949626 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] Routing type:
  962. 2022-06-29 11:30:40.949626 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] ================================================================
  963. 2022-06-29 11:30:40.949626 98.97% [INFO] switch_cpp.cpp:1465 [ASTPP] [FIND_MAXLENGTH] Your5000 balance Accountid 17 !!!
  964. 2022-06-29 11:30:40.949626 98.97% [NOTICE] switch_cpp.cpp:1465 [ASTPP] 22 Minutes
  965. 2022-06-29 11:30:40.949626 98.97% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [SAY_TIMELIMIT] MINUTES 22
  966. 2022-06-29 11:30:40.949626 98.97% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-this-call-will-last.wav sample rate 16000 doesn't match requested rate 8000
  967. 2022-06-29 11:30:40.949626 98.97% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  968. 2022-06-29 11:30:42.129694 98.97% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-this-call-will-last.wav
  969. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 say(en number pronounced 22)
  970. 2022-06-29 11:30:42.149632 98.97% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  971. 2022-06-29 11:30:43.249640 99.03% [DEBUG] switch_ivr_play_say.c:2001 done playing file file_string://digits/20.wav!digits/2.wav
  972. 2022-06-29 11:30:43.249640 99.03% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-minutes.wav sample rate 16000 doesn't match requested rate 8000
  973. 2022-06-29 11:30:43.249640 99.03% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  974. 2022-06-29 11:30:43.869690 99.03% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-minutes.wav
  975. 2022-06-29 11:30:43.869690 99.03% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_CARRIER_RATES] Query :SELECT TK.id as trunk_id,TK.name as trunk_name,TK.codec,GW.name as path,GW.dialplan_variable,TK.provider_id,TR.init_inc,TK.status,TK.maxchannels,TK.cps,TK.leg_timeout,TR.pattern,TR.id as outbound_route_id,TR.connectcost,TR.comment,TR.includedseconds,TR.cost,TR.inc,TR.prepend,TR.strip,(select name from gateways where status=0 AND id = TK.failover_gateway_id) as path1,(select name from gateways where status=0 AND id = TK.failover_gateway_id1) as path2 FROM outbound_routes as TR,trunks as TK,gateways as GW WHERE GW.status=0 AND GW.id= TK.gateway_id AND TK.status=0 AND TK.id= TR.trunk_id AND (pattern = '^90779205097.*' OR pattern = '^9077920509.*' OR pattern = '^907792050.*' OR pattern = '^90779205.*' OR pattern = '^9077920.*' OR pattern = '^907792.*' OR pattern = '^90779.*' OR pattern = '^9077.*' OR pattern = '^907.*' OR pattern = '^90.*' OR pattern = '^9.*' OR pattern ='--') AND TR.status = 0  AND TR.trunk_id IN (3)  ORDER by LENGTH (pattern) DESC,TR.cost ASC,TR.precedence ASC, TK.precedence
  976. 2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Termination Rates Information ===================
  977. 2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] ID : 6
  978. 2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] Code : ^90.*
  979. 2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] Destination : Uganda
  980. 2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] Connectcost : 0.00000
  981. 2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] Free Seconds : 0
  982. 2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] Prefix : ^90.*
  983. 2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] Strip : 9
  984. 2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] Termination rate id : 3
  985. 2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] Gateway name : MTN
  986. 2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] Failover gateway :
  987. 2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] Vendor id : 18
  988. 2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] Max channels : 0
  989. 2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] trunk_name : MTN
  990. 2022-06-29 11:30:43.889631 99.03% [INFO] switch_cpp.cpp:1465 [ASTPP] =================================================================
  991. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(call_processed=internal)
  992. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [call_processed]=[internal]
  993. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(callstart=2022-06-29 08:30:43)
  994. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [callstart]=[2022-06-29 08:30:43]
  995. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(originated_destination_number=90779205097)
  996. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [originated_destination_number]=[90779205097]
  997. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(effective_destination_number=90779205097)
  998. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [effective_destination_number]=[90779205097]
  999. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(continue_on_fail=true)
  1000. 2022-06-29 11:30:43.889631 99.03% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [continue_on_fail]=[true]
  1001. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(hangup_after_bridge=true)
  1002. 2022-06-29 11:30:43.889631 99.03% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [hangup_after_bridge]=[true]
  1003. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(account_id=17)
  1004. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [account_id]=[17]
  1005. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(account_type=0)
  1006. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [account_type]=[0]
  1007. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(resellerid=0)
  1008. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [resellerid]=[0]
  1009. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(parent_id=0)
  1010. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [parent_id]=[0]
  1011. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(accountcode=127718)
  1012. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [accountcode]=[127718]
  1013. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(call_direction=outbound)
  1014. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [call_direction]=[outbound]
  1015. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(calltype=CALLINGCARD)
  1016. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [calltype]=[CALLINGCARD]
  1017. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(origination_rates=ID:8|CODE:^907.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:1|COST:220.00000|INC:60|INITIALBLOCK:60|RATEGROUP:4|MARKUP:0|CI:197|ACCID:17)
  1018. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [origination_rates]=[ID:8|CODE:^907.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:1|COST:220.00000|INC:60|INITIALBLOCK:60|RATEGROUP:4|MARKUP:0|CI:197|ACCID:17]
  1019. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(execute_on_answer=sched_hangup +1320)
  1020. 2022-06-29 11:30:43.889631 99.03% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [execute_on_answer]=[sched_hangup +1320]
  1021. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(process_cdr=true)
  1022. 2022-06-29 11:30:43.889631 99.03% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [process_cdr]=[true]
  1023. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 sched_hangup(+1320)
  1024. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_scheduler.c:263 Added task 5 switch_ivr_schedule_hangup (c71261ca-c074-4061-a372-aa03d5185441) to run at 1656492763
  1025. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_OVERRIDE_CALLERID] Query :SELECT callerid_name as cid_name,callerid_number as cid_number,accountid FROM accounts_callerid WHERE accountid = 17 AND status=0 LIMIT 1
  1026. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(original_caller_id_name=0902)
  1027. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [original_caller_id_name]=[0902]
  1028. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(original_caller_id_number=0902)
  1029. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [original_caller_id_number]=[0902]
  1030. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(presence_data=x|||Dorcas(127718)|||^907.* // Uganda // 220.00000|||MTN // ^90.* // Uganda // 220.00000|||CC)
  1031. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [presence_data]=[x|||Dorcas(127718)|||^907.* // Uganda // 220.00000|||MTN // ^90.* // Uganda // 220.00000|||CC]
  1032. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,out_caller_id_terminate,number_terminate FROM localization WHERE id=(SELECT localization_id from accounts where id = 18) AND status=0 limit 1
  1033. 2022-06-29 11:30:43.889631 99.03% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [DONUMBERTRANSLATION] Before Localization CLI/DST : 90779205097
  1034. 2022-06-29 11:30:43.889631 99.03% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [DONUMBERTRANSLATION] After Localization CLI/DST : 0779205097
  1035. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(termination_rates=ID:6|CODE:^90.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:220.00000|INC:60|TRUNK:3|PROVIDER:18)
  1036. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [termination_rates]=[ID:6|CODE:^90.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:220.00000|INC:60|TRUNK:3|PROVIDER:18]
  1037. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(trunk_id=3)
  1038. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [trunk_id]=[3]
  1039. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(provider_id=18)
  1040. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [provider_id]=[18]
  1041. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(hangup_after_bridge=false)
  1042. 2022-06-29 11:30:43.889631 99.03% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [hangup_after_bridge]=[false]
  1043. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(absolute_codec_string=PCMA,G729,PCMA)
  1044. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [absolute_codec_string]=[PCMA,G729,PCMA]
  1045. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 bridge([leg_timeout=0]sofia/gateway/MTN/0779205097)
  1046. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1954 (sofia/default/0902@102.220.200.133) Callstate Change ACTIVE -> RING_WAIT
  1047. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [call_processed]=[internal] to event
  1048. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [callstart]=[2022-06-29 08:30:43] to event
  1049. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [originated_destination_number]=[90779205097] to event
  1050. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [effective_destination_number]=[90779205097] to event
  1051. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [account_id]=[17] to event
  1052. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [account_type]=[0] to event
  1053. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [resellerid]=[0] to event
  1054. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [parent_id]=[0] to event
  1055. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [accountcode]=[127718] to event
  1056. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [call_direction]=[outbound] to event
  1057. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [calltype]=[CALLINGCARD] to event
  1058. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [origination_rates]=[ID:8|CODE:^907.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:1|COST:220.00000|INC:60|INITIALBLOCK:60|RATEGROUP:4|MARKUP:0|CI:197|ACCID:17] to event
  1059. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [original_caller_id_name]=[0902] to event
  1060. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [original_caller_id_number]=[0902] to event
  1061. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [presence_data]=[x|||Dorcas(127718)|||^907.* // Uganda // 220.00000|||MTN // ^90.* // Uganda // 220.00000|||CC] to event
  1062. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [termination_rates]=[ID:6|CODE:^90.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:220.00000|INC:60|TRUNK:3|PROVIDER:18] to event
  1063. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [trunk_id]=[3] to event
  1064. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [provider_id]=[18] to event
  1065. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [absolute_codec_string]=[PCMA,G729,PCMA] to event
  1066. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
  1067. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_ivr_originate.c:2843 Parsing session specific variables
  1068. 2022-06-29 11:30:43.889631 99.03% [NOTICE] switch_channel.c:1123 New Channel sofia/default/0779205097 [f9d92969-278e-4af7-9ec5-da3db01f8cda]
  1069. 2022-06-29 11:30:43.889631 99.03% [DEBUG] mod_sofia.c:5121 (sofia/default/0779205097) State Change CS_NEW -> CS_INIT
  1070. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0779205097) Running State Change CS_INIT (Cur 2 Tot 707)
  1071. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:624 (sofia/default/0779205097) State INIT
  1072. 2022-06-29 11:30:43.889631 99.03% [DEBUG] mod_sofia.c:97 sofia/default/0779205097 SOFIA INIT
  1073. 2022-06-29 11:30:43.889631 99.03% [INFO] sofia_glue.c:1651 sofia/default/0779205097 sending invite call-id: (null)
  1074. 2022-06-29 11:30:43.889631 99.03% [DEBUG] sofia_glue.c:1654 sofia/default/0779205097 sending invite version: 1.10.7 -release-19-883d2cb662 64bit
  1075. Local SDP:
  1076. v=0
  1077. o=FreeSWITCH 1656463215 1656463216 IN IP4 102.220.200.133
  1078. s=FreeSWITCH
  1079. c=IN IP4 102.220.200.133
  1080. t=0 0
  1081. m=audio 28228 RTP/AVP 8 18 101
  1082. a=rtpmap:8 PCMA/8000
  1083. a=rtpmap:18 G729/8000
  1084. a=rtpmap:101 telephone-event/8000
  1085. a=fmtp:101 0-15
  1086. a=ptime:20
  1087. a=sendrecv
  1088.  
  1089. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:40 sofia/default/0779205097 Standard INIT
  1090. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:48 (sofia/default/0779205097) State Change CS_INIT -> CS_ROUTING
  1091. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:624 (sofia/default/0779205097) State INIT going to sleep
  1092. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0779205097) Running State Change CS_ROUTING (Cur 2 Tot 707)
  1093. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:640 (sofia/default/0779205097) State ROUTING
  1094. 2022-06-29 11:30:43.889631 99.03% [DEBUG] mod_sofia.c:158 sofia/default/0779205097 SOFIA ROUTING
  1095. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_ivr_originate.c:67 (sofia/default/0779205097) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  1096. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:640 (sofia/default/0779205097) State ROUTING going to sleep
  1097. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0779205097) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 707)
  1098. 2022-06-29 11:30:43.889631 99.03% [DEBUG] sofia.c:7499 Channel sofia/default/0779205097 entering state [calling][0]
  1099. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:659 (sofia/default/0779205097) State CONSUME_MEDIA
  1100. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:659 (sofia/default/0779205097) State CONSUME_MEDIA going to sleep
  1101. 2022-06-29 11:30:43.889631 99.03% [DEBUG] sofia.c:7499 Channel sofia/default/0779205097 entering state [terminated][503]
  1102. 2022-06-29 11:30:43.889631 99.03% [NOTICE] sofia.c:8738 Hangup sofia/default/0779205097 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE]
  1103. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0779205097) Running State Change CS_HANGUP (Cur 2 Tot 707)
  1104. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:844 (sofia/default/0779205097) Callstate Change DOWN -> HANGUP
  1105. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:846 (sofia/default/0779205097) State HANGUP
  1106. 2022-06-29 11:30:43.889631 99.03% [DEBUG] mod_sofia.c:468 Channel sofia/default/0779205097 hanging up, cause: NORMAL_TEMPORARY_FAILURE
  1107. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE]
  1108. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:59 sofia/default/0779205097 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
  1109. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:846 (sofia/default/0779205097) State HANGUP going to sleep
  1110. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:616 (sofia/default/0779205097) State Change CS_HANGUP -> CS_REPORTING
  1111. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0779205097) Running State Change CS_REPORTING (Cur 2 Tot 707)
  1112. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_state_machine.c:932 (sofia/default/0779205097) State REPORTING
  1113. 2022-06-29 11:30:43.889631 99.03% [INFO] mod_json_cdr.c:271 Process [f9d92969-278e-4af7-9ec5-da3db01f8cda.cdr.json]
  1114. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_channel.c:2178 (sofia/default/0902@102.220.200.133) Callstate Change RING_WAIT -> ACTIVE
  1115. 2022-06-29 11:30:43.889631 99.03% [INFO] mod_dptools.c:3653 Originate Failed.  Cause: NORMAL_TEMPORARY_FAILURE
  1116. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-callingcard-menu.wav sample rate 16000 doesn't match requested rate 8000
  1117. 2022-06-29 11:30:43.889631 99.03% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  1118. 2022-06-29 11:30:43.989668 99.03% [DEBUG] switch_core_state_machine.c:168 sofia/default/0779205097 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
  1119. 2022-06-29 11:30:43.989668 99.03% [DEBUG] switch_core_state_machine.c:932 (sofia/default/0779205097) State REPORTING going to sleep
  1120. 2022-06-29 11:30:43.989668 99.03% [DEBUG] switch_core_state_machine.c:607 (sofia/default/0779205097) State Change CS_REPORTING -> CS_DESTROY
  1121. 2022-06-29 11:30:43.989668 99.03% [DEBUG] switch_core_session.c:1753 Session 707 (sofia/default/0779205097) Locked, Waiting on external entities
  1122. 2022-06-29 11:30:43.989668 99.03% [NOTICE] switch_core_session.c:1771 Session 707 (sofia/default/0779205097) Ended
  1123. 2022-06-29 11:30:43.989668 99.03% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/0779205097 [CS_DESTROY]
  1124. 2022-06-29 11:30:43.989668 99.03% [DEBUG] switch_core_state_machine.c:735 (sofia/default/0779205097) Running State Change CS_DESTROY (Cur 1 Tot 707)
  1125. 2022-06-29 11:30:43.989668 99.03% [DEBUG] switch_core_state_machine.c:745 (sofia/default/0779205097) State DESTROY
  1126. 2022-06-29 11:30:43.989668 99.03% [DEBUG] mod_sofia.c:379 sofia/default/0779205097 SOFIA DESTROY
  1127. 2022-06-29 11:30:43.989668 99.03% [DEBUG] switch_core_state_machine.c:175 sofia/default/0779205097 Standard DESTROY
  1128. 2022-06-29 11:30:43.989668 99.03% [DEBUG] switch_core_state_machine.c:745 (sofia/default/0779205097) State DESTROY going to sleep
  1129. 2022-06-29 11:30:50.049690 98.83% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-callingcard-menu.wav
  1130. 2022-06-29 11:30:52.009662 98.87% [NOTICE] sofia.c:1065 Hangup sofia/default/0902@102.220.200.133 [CS_EXECUTE] [NORMAL_CLEARING]
  1131. 2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Got DTMF digits: retries:0
  1132. 2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Got DTMF digits: retries:1
  1133. 2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Got DTMF digits: retries:2
  1134. 2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_cpp.cpp:749 CoreSession::hangup
  1135. 2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_cpp.cpp:1209 sofia/default/0902@102.220.200.133 destroy/unlink session from object
  1136. 2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_session.c:2983 sofia/default/0902@102.220.200.133 skip receive message [PHONE_EVENT] (channel is hungup already)
  1137. 2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:647 (sofia/default/0902@102.220.200.133) State EXECUTE going to sleep
  1138. 2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_HANGUP (Cur 1 Tot 707)
  1139. 2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:844 (sofia/default/0902@102.220.200.133) Callstate Change ACTIVE -> HANGUP
  1140. 2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:846 (sofia/default/0902@102.220.200.133) State HANGUP
  1141. 2022-06-29 11:30:52.009662 98.87% [DEBUG] mod_sofia.c:462 sofia/default/0902@102.220.200.133 Overriding SIP cause 480 with 503 from the other leg
  1142. 2022-06-29 11:30:52.009662 98.87% [DEBUG] mod_sofia.c:468 Channel sofia/default/0902@102.220.200.133 hanging up, cause: NORMAL_CLEARING
  1143. 2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:59 sofia/default/0902@102.220.200.133 Standard HANGUP, cause: NORMAL_CLEARING
  1144. 2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:846 (sofia/default/0902@102.220.200.133) State HANGUP going to sleep
  1145. 2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:616 (sofia/default/0902@102.220.200.133) State Change CS_HANGUP -> CS_REPORTING
  1146. 2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_REPORTING (Cur 1 Tot 707)
  1147. 2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:932 (sofia/default/0902@102.220.200.133) State REPORTING
  1148. 2022-06-29 11:30:52.009662 98.87% [INFO] mod_json_cdr.c:271 Process [c71261ca-c074-4061-a372-aa03d5185441.cdr.json]
  1149. 2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:168 sofia/default/0902@102.220.200.133 Standard REPORTING, cause: NORMAL_CLEARING
  1150. 2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:932 (sofia/default/0902@102.220.200.133) State REPORTING going to sleep
  1151. 2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:607 (sofia/default/0902@102.220.200.133) State Change CS_REPORTING -> CS_DESTROY
  1152. 2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_session.c:1753 Session 706 (sofia/default/0902@102.220.200.133) Locked, Waiting on external entities
  1153. 2022-06-29 11:30:52.009662 98.87% [NOTICE] switch_core_session.c:1771 Session 706 (sofia/default/0902@102.220.200.133) Ended
  1154. 2022-06-29 11:30:52.009662 98.87% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/0902@102.220.200.133 [CS_DESTROY]
  1155. 2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:735 (sofia/default/0902@102.220.200.133) Running State Change CS_DESTROY (Cur 0 Tot 707)
  1156. 2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:745 (sofia/default/0902@102.220.200.133) State DESTROY
  1157. 2022-06-29 11:30:52.009662 98.87% [DEBUG] mod_sofia.c:379 sofia/default/0902@102.220.200.133 SOFIA DESTROY
  1158. 2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:175 sofia/default/0902@102.220.200.133 Standard DESTROY
  1159. 2022-06-29 11:30:52.009662 98.87% [DEBUG] switch_core_state_machine.c:745 (sofia/default/0902@102.220.200.133) State DESTROY going to sleep
  1160. 2022-06-29 11:30:52.389694 98.87% [DEBUG] switch_scheduler.c:147 Deleting task 5 switch_ivr_schedule_hangup (c71261ca-c074-4061-a372-aa03d5185441)
  1161. 2022-06-29 11:31:22.409694 97.93% [NOTICE] switch_channel.c:1123 New Channel sofia/default/0902@102.220.200.133 [a5859f66-b4eb-44b9-aaeb-61a5d3692597]
  1162. 2022-06-29 11:31:22.409694 97.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_NEW (Cur 1 Tot 708)
  1163. 2022-06-29 11:31:22.409694 97.93% [INFO] sofia.c:10462 sofia/default/0902@102.220.200.133 receiving invite from 102.220.201.145:5060 version: 1.10.7 -release-19-883d2cb662 64bit call-id: 13a8b29b-dd6cbd60@102.220.201.145
  1164. 2022-06-29 11:31:22.409694 97.93% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 102.220.201.145:0.
  1165. 2022-06-29 11:31:22.409694 97.93% [WARNING] sofia_reg.c:1861 SIP auth challenge (INVITE) on sofia profile 'default' for [0000@102.220.200.133] from ip 102.220.201.145
  1166. 2022-06-29 11:31:22.409694 97.93% [DEBUG] switch_core_state_machine.c:600 (sofia/default/0902@102.220.200.133) State NEW
  1167. 2022-06-29 11:31:22.409694 97.93% [DEBUG] sofia.c:2419 detaching session a5859f66-b4eb-44b9-aaeb-61a5d3692597
  1168. 2022-06-29 11:31:22.429690 97.93% [DEBUG] sofia.c:2532 Re-attaching to session a5859f66-b4eb-44b9-aaeb-61a5d3692597
  1169. 2022-06-29 11:31:22.429690 97.93% [INFO] sofia.c:10462 sofia/default/0902@102.220.200.133 receiving invite from 102.220.201.145:5060 version: 1.10.7 -release-19-883d2cb662 64bit call-id: 13a8b29b-dd6cbd60@102.220.201.145
  1170. 2022-06-29 11:31:22.429690 97.93% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 102.220.201.145:0.
  1171. 2022-06-29 11:31:22.449641 97.93% [DEBUG] sofia.c:7499 Channel sofia/default/0902@102.220.200.133 entering state [received][100]
  1172. 2022-06-29 11:31:22.449641 97.93% [DEBUG] sofia.c:7509 Remote SDP:
  1173. v=0
  1174. o=- 14914752 14914752 IN IP4 102.220.201.145
  1175. s=-
  1176. c=IN IP4 102.220.201.145
  1177. t=0 0
  1178. m=audio 16384 RTP/AVP 0 2 8 9 18 96 97 98 101
  1179. a=rtpmap:0 PCMU/8000
  1180. a=rtpmap:2 G726-32/8000
  1181. a=rtpmap:8 PCMA/8000
  1182. a=rtpmap:9 G722/8000
  1183. a=rtpmap:18 G729a/8000
  1184. a=rtpmap:96 G726-40/8000
  1185. a=rtpmap:97 G726-24/8000
  1186. a=rtpmap:98 G726-16/8000
  1187. a=rtpmap:101 telephone-event/8000
  1188. a=fmtp:101 0-15
  1189. a=ptime:30
  1190.  
  1191. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:30:64000:1]/[PCMA:8:8000:20:64000:1]
  1192. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:30:64000:1]/[PCMU:0:8000:20:64000:1]
  1193. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5686 Audio Codec Compare [PCMU:0:8000:20:64000:1] is saved as a near-match
  1194. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-32:2:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
  1195. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-32:2:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
  1196. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:30:64000:1]/[PCMA:8:8000:20:64000:1]
  1197. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5686 Audio Codec Compare [PCMA:8:8000:20:64000:1] is saved as a near-match
  1198. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:30:64000:1]/[PCMU:0:8000:20:64000:1]
  1199. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G722:9:8000:30:64000:1]/[PCMA:8:8000:20:64000:1]
  1200. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G722:9:8000:30:64000:1]/[PCMU:0:8000:20:64000:1]
  1201. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729a:18:8000:30:8000:1]/[PCMA:8:8000:20:64000:1]
  1202. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G729a:18:8000:30:8000:1]/[PCMU:0:8000:20:64000:1]
  1203. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-40:96:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
  1204. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-40:96:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
  1205. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-24:97:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
  1206. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-24:97:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
  1207. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-16:98:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
  1208. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [G726-16:98:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
  1209. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5566 Set telephone-event payload to 101@8000
  1210. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5757 Substituting codec PCMU@30i@8000h@1c
  1211. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:3870 Set Codec sofia/default/0902@102.220.200.133 PCMU/8000 30 ms 240 samples 64000 bits 1 channels
  1212. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_codec.c:111 sofia/default/0902@102.220.200.133 Original read codec set to PCMU:0
  1213. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5915 Set telephone-event payload to 101@8000
  1214. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:5973 sofia/default/0902@102.220.200.133 Set 2833 dtmf send payload to 101 recv payload to 101
  1215. 2022-06-29 11:31:22.449641 97.93% [DEBUG] sofia.c:7933 (sofia/default/0902@102.220.200.133) State Change CS_NEW -> CS_INIT
  1216. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_INIT (Cur 1 Tot 708)
  1217. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_state_machine.c:624 (sofia/default/0902@102.220.200.133) State INIT
  1218. 2022-06-29 11:31:22.449641 97.93% [DEBUG] mod_sofia.c:97 sofia/default/0902@102.220.200.133 SOFIA INIT
  1219. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_state_machine.c:40 sofia/default/0902@102.220.200.133 Standard INIT
  1220. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_state_machine.c:48 (sofia/default/0902@102.220.200.133) State Change CS_INIT -> CS_ROUTING
  1221. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_state_machine.c:624 (sofia/default/0902@102.220.200.133) State INIT going to sleep
  1222. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_ROUTING (Cur 1 Tot 708)
  1223. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_channel.c:2380 (sofia/default/0902@102.220.200.133) Callstate Change DOWN -> RINGING
  1224. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_state_machine.c:640 (sofia/default/0902@102.220.200.133) State ROUTING
  1225. 2022-06-29 11:31:22.449641 97.93% [DEBUG] mod_sofia.c:158 sofia/default/0902@102.220.200.133 SOFIA ROUTING
  1226. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_state_machine.c:230 sofia/default/0902@102.220.200.133 Standard ROUTING
  1227. 2022-06-29 11:31:22.449641 97.93% [INFO] mod_dialplan_xml.c:639 Processing 0902 <0902>->0000 in context default
  1228. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes')
  1229. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
  1230. 2022-06-29 11:31:22.449641 97.93% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] Dialed number : 0000
  1231. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT access_number FROM accessnumber WHERE access_number = '0000' AND status=0 limit 1
  1232. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Generated XML:
  1233. <?xml version="1.0" encoding="UTF-8" standalone="no"?>
  1234. <document type="freeswitch/xml">
  1235. <section name="dialplan" description="ASTPP Dialplan">
  1236. <context name="default">
  1237. <extension name="0000">
  1238. <condition field="destination_number" expression="0000">
  1239. <action application="log" data="INFO ASTPP - Calling Card Call"/>
  1240. <action application="answer"/>
  1241. <action application="sleep" data="2000"/>
  1242. <action application="lua" data="astpp-callingcards.lua"/>
  1243. </condition>
  1244. </extension>
  1245. </context>
  1246. </section>
  1247. </document>
  1248. Dialplan: sofia/default/0902@102.220.200.133 parsing [default->0000] continue=false
  1249. Dialplan: sofia/default/0902@102.220.200.133 Regex (PASS) [0000] destination_number(0000) =~ /0000/ break=on-false
  1250. Dialplan: sofia/default/0902@102.220.200.133 Action log(INFO ASTPP - Calling Card Call)
  1251. Dialplan: sofia/default/0902@102.220.200.133 Action answer()
  1252. Dialplan: sofia/default/0902@102.220.200.133 Action sleep(2000)
  1253. Dialplan: sofia/default/0902@102.220.200.133 Action lua(astpp-callingcards.lua)
  1254. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_state_machine.c:281 (sofia/default/0902@102.220.200.133) State Change CS_ROUTING -> CS_EXECUTE
  1255. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_state_machine.c:640 (sofia/default/0902@102.220.200.133) State ROUTING going to sleep
  1256. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_EXECUTE (Cur 1 Tot 708)
  1257. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_state_machine.c:647 (sofia/default/0902@102.220.200.133) State EXECUTE
  1258. 2022-06-29 11:31:22.449641 97.93% [DEBUG] mod_sofia.c:213 sofia/default/0902@102.220.200.133 SOFIA EXECUTE
  1259. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_state_machine.c:323 sofia/default/0902@102.220.200.133 Standard EXECUTE
  1260. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 log(INFO ASTPP - Calling Card Call)
  1261. 2022-06-29 11:31:22.449641 97.93% [INFO] mod_dptools.c:1879 ASTPP - Calling Card Call
  1262. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 answer()
  1263. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_core_media.c:8777 AUDIO RTP [sofia/default/0902@102.220.200.133] 102.220.200.133 port 24520 -> 102.220.201.145 port 16384 codec: 0 ms: 30
  1264. 2022-06-29 11:31:22.449641 97.93% [DEBUG] switch_rtp.c:4619 Starting timer [soft] 240 bytes per 30ms
  1265. 2022-06-29 11:31:22.469613 97.93% [DEBUG] switch_core_media.c:9089 sofia/default/0902@102.220.200.133 Set 2833 dtmf send payload to 101
  1266. 2022-06-29 11:31:22.469613 97.93% [DEBUG] switch_core_media.c:9096 sofia/default/0902@102.220.200.133 Set 2833 dtmf receive payload to 101
  1267. 2022-06-29 11:31:22.469613 97.93% [DEBUG] switch_core_media.c:9119 sofia/default/0902@102.220.200.133 Set rtp dtmf delay to 40
  1268. 2022-06-29 11:31:22.469613 97.93% [DEBUG] mod_sofia.c:913 Local SDP sofia/default/0902@102.220.200.133:
  1269. v=0
  1270. o=FreeSWITCH 1656466962 1656466963 IN IP4 102.220.200.133
  1271. s=FreeSWITCH
  1272. c=IN IP4 102.220.200.133
  1273. t=0 0
  1274. m=audio 24520 RTP/AVP 0 101
  1275. a=rtpmap:0 PCMU/8000
  1276. a=rtpmap:101 telephone-event/8000
  1277. a=fmtp:101 0-15
  1278. a=ptime:30
  1279. a=sendrecv
  1280.  
  1281. 2022-06-29 11:31:22.469613 97.93% [NOTICE] mod_dptools.c:1419 Channel [sofia/default/0902@102.220.200.133] has been answered
  1282. 2022-06-29 11:31:22.469613 97.93% [DEBUG] switch_channel.c:3950 (sofia/default/0902@102.220.200.133) Callstate Change RINGING -> ACTIVE
  1283. 2022-06-29 11:31:22.469613 97.93% [DEBUG] sofia.c:7499 Channel sofia/default/0902@102.220.200.133 entering state [completed][200]
  1284. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 sleep(2000)
  1285. 2022-06-29 11:31:22.509684 97.93% [DEBUG] sofia.c:7499 Channel sofia/default/0902@102.220.200.133 entering state [ready][200]
  1286. 2022-06-29 11:31:22.569691 97.93% [DEBUG] switch_rtp.c:7934 Correct audio ip/port confirmed.
  1287. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 lua(astpp-callingcards.lua)
  1288. 2022-06-29 11:31:24.489650 97.93% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','InternationalPrefixes')
  1289. 2022-06-29 11:31:24.489650 97.93% [NOTICE] switch_cpp.cpp:1465 [ASTPP] SECTION
  1290. 2022-06-29 11:31:24.489650 97.93% [DEBUG] switch_core_file.c:444 File /var/www/html/astpp/upload/astpp-welcome.wav sample rate 16000 doesn't match requested rate 8000
  1291. 2022-06-29 11:31:24.489650 97.93% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  1292. 2022-06-29 11:31:26.269653 98.10% [DEBUG] switch_ivr_play_say.c:2001 done playing file /var/www/html/astpp/upload/astpp-welcome.wav
  1293. 2022-06-29 11:31:26.269653 98.10% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-accountnum.wav sample rate 16000 doesn't match requested rate 8000
  1294. 2022-06-29 11:31:26.269653 98.10% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  1295. 2022-06-29 11:31:28.069671 98.30% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [687@102.220.200.133] from ip 138.199.60.166
  1296. 2022-06-29 11:31:28.489694 98.30% [WARNING] sofia_reg.c:3223 Can't find user [687@102.220.200.133] from 138.199.60.166
  1297. You must define a domain called '102.220.200.133' in your directory and add a user with the id="687" attribute
  1298. and you must configure your device to use the proper domain in its authentication credentials.
  1299. 2022-06-29 11:31:28.489694 98.30% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [687@102.220.200.133] from ip 138.199.60.166
  1300. 2022-06-29 11:31:28.969694 98.37% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:1360
  1301. 2022-06-29 11:31:28.969694 98.37% [INFO] switch_channel.c:527 RECV DTMF 1:1360
  1302. 2022-06-29 11:31:28.969694 98.37% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-accountnum.wav
  1303. 2022-06-29 11:31:29.329695 98.37% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 2:1040
  1304. 2022-06-29 11:31:29.329695 98.37% [INFO] switch_channel.c:527 RECV DTMF 2:1040
  1305. 2022-06-29 11:31:29.689696 98.40% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:800
  1306. 2022-06-29 11:31:29.689696 98.40% [INFO] switch_channel.c:527 RECV DTMF 7:800
  1307. 2022-06-29 11:31:29.949696 98.40% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:960
  1308. 2022-06-29 11:31:29.949696 98.40% [INFO] switch_channel.c:527 RECV DTMF 7:960
  1309. 2022-06-29 11:31:30.289700 98.40% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:880
  1310. 2022-06-29 11:31:30.289700 98.40% [INFO] switch_channel.c:527 RECV DTMF 1:880
  1311. 2022-06-29 11:31:30.349691 98.40% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [692@102.220.200.133] from ip 213.109.151.9
  1312. 2022-06-29 11:31:30.429691 98.40% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 91.240.243.18
  1313. 2022-06-29 11:31:30.549689 98.40% [WARNING] sofia_reg.c:3223 Can't find user [692@102.220.200.133] from 213.109.151.9
  1314. You must define a domain called '102.220.200.133' in your directory and add a user with the id="692" attribute
  1315. and you must configure your device to use the proper domain in its authentication credentials.
  1316. 2022-06-29 11:31:30.549689 98.40% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [692@102.220.200.133] from ip 213.109.151.9
  1317. 2022-06-29 11:31:30.649694 98.37% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 8:960
  1318. 2022-06-29 11:31:30.649694 98.37% [INFO] switch_channel.c:527 RECV DTMF 8:960
  1319. 2022-06-29 11:31:30.709664 98.37% [WARNING] sofia_reg.c:3223 Can't find user [769@102.220.200.133] from 91.240.243.18
  1320. You must define a domain called '102.220.200.133' in your directory and add a user with the id="769" attribute
  1321. and you must configure your device to use the proper domain in its authentication credentials.
  1322. 2022-06-29 11:31:30.709664 98.37% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 91.240.243.18
  1323. 2022-06-29 11:31:31.029692 98.37% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF #:1040
  1324. span style="color: green; font-weight: bold;"> 2022-06-29 11:31:31.029692 98.37% [INFO] switch_channel.c:527 RECV DTMF #:1040
  1325. span style="color: goldenrod; font-weight: bold;"> 2022-06-29 11:31:31.049667 98.37% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Got DTMF digits: 127718
  1326. 2022-06-29 11:31:31.049667 98.37% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT *,(select currencyrate from currency where id=currency_id) as currencyrate FROM accounts WHERE number = "127718" AND status=0 AND deleted=0 limit 1
  1327. 2022-06-29 11:31:31.049667 98.37% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-pleasepin.wav sample rate 16000 doesn't match requested rate 8000
  1328. 2022-06-29 11:31:31.049667 98.37% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  1329. 2022-06-29 11:31:33.709693 99.03% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 6:1360
  1330. 2022-06-29 11:31:33.709693 99.03% [INFO] switch_channel.c:527 RECV DTMF 6:1360
  1331. 2022-06-29 11:31:33.709693 99.03% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-pleasepin.wav
  1332. 2022-06-29 11:31:34.009693 99.03% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 3:720
  1333. 2022-06-29 11:31:34.009693 99.03% [INFO] switch_channel.c:527 RECV DTMF 3:720
  1334. 2022-06-29 11:31:34.389696 99.03% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 1:880
  1335. 2022-06-29 11:31:34.389696 99.03% [INFO] switch_channel.c:527 RECV DTMF 1:880
  1336. 2022-06-29 11:31:34.729695 99.03% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 4:1120
  1337. 2022-06-29 11:31:34.729695 99.03% [INFO] switch_channel.c:527 RECV DTMF 4:1120
  1338. 2022-06-29 11:31:35.209681 99.03% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF #:1200
  1339. span style="color: green; font-weight: bold;"> 2022-06-29 11:31:35.209681 99.03% [INFO] switch_channel.c:527 RECV DTMF #:1200
  1340. span style="color: goldenrod; font-weight: bold;"> 2022-06-29 11:31:35.209681 99.03% [DEBUG] switch_cpp.cpp:1465 [ASTPP] We recieved a pin : 6314
  1341. 2022-06-29 11:31:35.209681 99.03% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [validate_card_usage] Query :SELECT DATE_FORMAT('2032-06-21 10:11:08' , '%Y%m%d%H%i%s') AS expiry
  1342. 2022-06-29 11:31:35.209681 99.03% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [validate_card_usage] Query :SELECT DATE_FORMAT('2022-06-29 08:31:35' , '%Y%m%d%H%i%s') AS expiry
  1343. 2022-06-29 11:31:35.209681 99.03% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [Accountcode : 127718]
  1344. 2022-06-29 11:31:35.209681 99.03% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-this-card-has-a-balance-of.wav sample rate 16000 doesn't match requested rate 8000
  1345. 2022-06-29 11:31:35.209681 99.03% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  1346. 2022-06-29 11:31:36.529692 99.03% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-this-card-has-a-balance-of.wav
  1347. 2022-06-29 11:31:36.529692 99.03% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [Play Amount First Part] Query :5000
  1348. 2022-06-29 11:31:36.529692 99.03% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [Play Amount Second Part] Query :00
  1349. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 say(en number pronounced 5000)
  1350. 2022-06-29 11:31:36.549627 99.03% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  1351. 2022-06-29 11:31:37.749651 99.30% [DEBUG] switch_ivr_play_say.c:2001 done playing file file_string://digits/5.wav!digits/thousand.wav
  1352. 2022-06-29 11:31:37.769617 99.30% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-point.wav sample rate 16000 doesn't match requested rate 8000
  1353. 2022-06-29 11:31:37.769617 99.30% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  1354. 2022-06-29 11:31:38.329647 99.30% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-point.wav
  1355. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 say(en number pronounced 00)
  1356. 2022-06-29 11:31:38.349661 99.30% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  1357. 2022-06-29 11:31:38.969671 99.27% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [770@102.220.200.133] from ip 62.197.148.4
  1358. 2022-06-29 11:31:39.109696 99.27% [DEBUG] switch_ivr_play_say.c:2001 done playing file file_string://digits/0.wav
  1359. 2022-06-29 11:31:39.109696 99.27% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-phonenum.wav sample rate 16000 doesn't match requested rate 8000
  1360. 2022-06-29 11:31:39.109696 99.27% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  1361. 2022-06-29 11:31:39.149677 99.27% [WARNING] sofia_reg.c:3223 Can't find user [770@102.220.200.133] from 62.197.148.4
  1362. You must define a domain called '102.220.200.133' in your directory and add a user with the id="770" attribute
  1363. and you must configure your device to use the proper domain in its authentication credentials.
  1364. 2022-06-29 11:31:39.149677 99.27% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [770@102.220.200.133] from ip 62.197.148.4
  1365. 2022-06-29 11:31:42.829696 99.13% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-phonenum.wav
  1366. 2022-06-29 11:31:44.449697 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 9:1360
  1367. 2022-06-29 11:31:44.449697 99.13% [INFO] switch_channel.c:527 RECV DTMF 9:1360
  1368. 2022-06-29 11:31:44.809704 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 0:880
  1369. 2022-06-29 11:31:44.809704 99.13% [INFO] switch_channel.c:527 RECV DTMF 0:880
  1370. 2022-06-29 11:31:45.129699 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:720
  1371. 2022-06-29 11:31:45.129699 99.13% [INFO] switch_channel.c:527 RECV DTMF 7:720
  1372. 2022-06-29 11:31:45.409699 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:800
  1373. 2022-06-29 11:31:45.409699 99.13% [INFO] switch_channel.c:527 RECV DTMF 7:800
  1374. 2022-06-29 11:31:45.789696 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 9:1440
  1375. 2022-06-29 11:31:45.789696 99.13% [INFO] switch_channel.c:527 RECV DTMF 9:1440
  1376. 2022-06-29 11:31:46.149693 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 2:1120
  1377. 2022-06-29 11:31:46.149693 99.13% [INFO] switch_channel.c:527 RECV DTMF 2:1120
  1378. 2022-06-29 11:31:46.569695 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 0:960
  1379. 2022-06-29 11:31:46.569695 99.13% [INFO] switch_channel.c:527 RECV DTMF 0:960
  1380. 2022-06-29 11:31:46.969699 99.10% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 5:800
  1381. 2022-06-29 11:31:46.969699 99.10% [INFO] switch_channel.c:527 RECV DTMF 5:800
  1382. 2022-06-29 11:31:47.329699 99.10% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 0:880
  1383. 2022-06-29 11:31:47.329699 99.10% [INFO] switch_channel.c:527 RECV DTMF 0:880
  1384. 2022-06-29 11:31:47.649695 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 9:880
  1385. 2022-06-29 11:31:47.649695 99.13% [INFO] switch_channel.c:527 RECV DTMF 9:880
  1386. 2022-06-29 11:31:48.009695 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 7:880
  1387. 2022-06-29 11:31:48.009695 99.13% [INFO] switch_channel.c:527 RECV DTMF 7:880
  1388. 2022-06-29 11:31:48.609693 99.13% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF #:1520
  1389. span style="color: green; font-weight: bold;"> 2022-06-29 11:31:48.609693 99.13% [INFO] switch_channel.c:527 RECV DTMF #:1520
  1390. span style="color: green; font-weight: bold;"> 2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] [CHECK_destination] Dialed destination number :90779205097
  1391. 2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Account Information ===================
  1392. 2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] User id : 17
  1393. 2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] Account code : 127718
  1394. 2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] Balance : 5000
  1395. 2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] Type : 0 [0:prepaid,1:postpaid]
  1396. 2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] Ratecard id : 4
  1397. 2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] ========================================================
  1398. 2022-06-29 11:31:48.629672 99.13% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CHECK_BLOCKED_PREFIX] Query :SELECT * FROM block_patterns WHERE (blocked_patterns = '^90779205097.*' OR blocked_patterns = '^9077920509.*' OR blocked_patterns = '^907792050.*' OR blocked_patterns = '^90779205.*' OR blocked_patterns = '^9077920.*' OR blocked_patterns = '^907792.*' OR blocked_patterns = '^90779.*' OR blocked_patterns = '^9077.*' OR blocked_patterns = '^907.*' OR blocked_patterns = '^90.*' OR blocked_patterns = '^9.*' OR blocked_patterns ='--') AND accountid = 17 limit 1
  1399. 2022-06-29 11:31:48.629672 99.13% [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 (patterns = '^90779205097.*' OR patterns = '^9077920509.*' OR patterns = '^907792050.*' OR patterns = '^90779205.*' OR patterns = '^9077920.*' OR patterns = '^907792.*' OR patterns = '^90779.*' OR patterns = '^9077.*' OR patterns = '^907.*' OR patterns = '^90.*' OR patterns = '^9.*' OR patterns ='--') AND accountid = 17 ORDER BY LENGTH(PKGPTR.patterns) DESC
  1400. 2022-06-29 11:31:48.629672 99.13% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 4 AND status = 0
  1401. 2022-06-29 11:31:48.629672 99.13% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_RATES] call_direction :
  1402. 2022-06-29 11:31:48.629672 99.13% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_RATES] Query :SELECT * FROM routes WHERE (pattern = '^90779205097.*' OR pattern = '^9077920509.*' OR pattern = '^907792050.*' OR pattern = '^90779205.*' OR pattern = '^9077920.*' OR pattern = '^907792.*' OR pattern = '^90779.*' OR pattern = '^9077.*' OR pattern = '^907.*' OR pattern = '^90.*' OR pattern = '^9.*' OR pattern ='--') AND status = 0 AND (pricelist_id = 4 OR accountid=17)  ORDER BY accountid DESC,LENGTH(pattern) DESC,cost DESC LIMIT 1
  1403. 2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] call_direction::::::
  1404. 2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Rates Information ===================
  1405. 2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] ID : 8
  1406. 2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] Connectcost : 0.00000
  1407. 2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] Includedseconds : 0
  1408. 2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] Cost : 220.00000
  1409. 2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] comment : Uganda
  1410. 2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] Country Id : 197
  1411. 2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] Accid : 17
  1412. 2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] Trunk ID: 3
  1413. 2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] Routing type:
  1414. 2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] ================================================================
  1415. 2022-06-29 11:31:48.629672 99.13% [INFO] switch_cpp.cpp:1465 [ASTPP] [FIND_MAXLENGTH] Your5000 balance Accountid 17 !!!
  1416. 2022-06-29 11:31:48.629672 99.13% [NOTICE] switch_cpp.cpp:1465 [ASTPP] 22 Minutes
  1417. 2022-06-29 11:31:48.629672 99.13% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [SAY_TIMELIMIT] MINUTES 22
  1418. 2022-06-29 11:31:48.629672 99.13% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-this-call-will-last.wav sample rate 16000 doesn't match requested rate 8000
  1419. 2022-06-29 11:31:48.629672 99.13% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  1420. 2022-06-29 11:31:49.809694 99.10% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-this-call-will-last.wav
  1421. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 say(en number pronounced 22)
  1422. 2022-06-29 11:31:49.849656 99.10% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  1423. 2022-06-29 11:31:50.929695 99.07% [DEBUG] switch_ivr_play_say.c:2001 done playing file file_string://digits/20.wav!digits/2.wav
  1424. 2022-06-29 11:31:50.929695 99.07% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-minutes.wav sample rate 16000 doesn't match requested rate 8000
  1425. 2022-06-29 11:31:50.929695 99.07% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  1426. 2022-06-29 11:31:51.549667 99.07% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-minutes.wav
  1427. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_CARRIER_RATES] Query :SELECT TK.id as trunk_id,TK.name as trunk_name,TK.codec,GW.name as path,GW.dialplan_variable,TK.provider_id,TR.init_inc,TK.status,TK.maxchannels,TK.cps,TK.leg_timeout,TR.pattern,TR.id as outbound_route_id,TR.connectcost,TR.comment,TR.includedseconds,TR.cost,TR.inc,TR.prepend,TR.strip,(select name from gateways where status=0 AND id = TK.failover_gateway_id) as path1,(select name from gateways where status=0 AND id = TK.failover_gateway_id1) as path2 FROM outbound_routes as TR,trunks as TK,gateways as GW WHERE GW.status=0 AND GW.id= TK.gateway_id AND TK.status=0 AND TK.id= TR.trunk_id AND (pattern = '^90779205097.*' OR pattern = '^9077920509.*' OR pattern = '^907792050.*' OR pattern = '^90779205.*' OR pattern = '^9077920.*' OR pattern = '^907792.*' OR pattern = '^90779.*' OR pattern = '^9077.*' OR pattern = '^907.*' OR pattern = '^90.*' OR pattern = '^9.*' OR pattern ='--') AND TR.status = 0  AND TR.trunk_id IN (3)  ORDER by LENGTH (pattern) DESC,TR.cost ASC,TR.precedence ASC, TK.precedence
  1428. 2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] =============== Termination Rates Information ===================
  1429. 2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] ID : 6
  1430. 2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] Code : ^90.*
  1431. 2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] Destination : Uganda
  1432. 2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] Connectcost : 0.00000
  1433. 2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] Free Seconds : 0
  1434. 2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] Prefix : ^90.*
  1435. 2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] Strip : 9
  1436. 2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] Termination rate id : 3
  1437. 2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] Gateway name : MTN
  1438. 2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] Failover gateway :
  1439. 2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] Vendor id : 18
  1440. 2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] Max channels : 0
  1441. 2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] trunk_name : MTN
  1442. 2022-06-29 11:31:51.569670 99.07% [INFO] switch_cpp.cpp:1465 [ASTPP] =================================================================
  1443. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(call_processed=internal)
  1444. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [call_processed]=[internal]
  1445. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(callstart=2022-06-29 08:31:51)
  1446. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [callstart]=[2022-06-29 08:31:51]
  1447. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(originated_destination_number=90779205097)
  1448. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [originated_destination_number]=[90779205097]
  1449. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(effective_destination_number=90779205097)
  1450. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [effective_destination_number]=[90779205097]
  1451. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(continue_on_fail=true)
  1452. 2022-06-29 11:31:51.569670 99.07% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [continue_on_fail]=[true]
  1453. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(hangup_after_bridge=true)
  1454. 2022-06-29 11:31:51.569670 99.07% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [hangup_after_bridge]=[true]
  1455. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(account_id=17)
  1456. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [account_id]=[17]
  1457. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(account_type=0)
  1458. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [account_type]=[0]
  1459. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(resellerid=0)
  1460. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [resellerid]=[0]
  1461. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(parent_id=0)
  1462. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [parent_id]=[0]
  1463. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(accountcode=127718)
  1464. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [accountcode]=[127718]
  1465. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(call_direction=outbound)
  1466. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [call_direction]=[outbound]
  1467. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(calltype=CALLINGCARD)
  1468. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [calltype]=[CALLINGCARD]
  1469. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(origination_rates=ID:8|CODE:^907.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:1|COST:220.00000|INC:60|INITIALBLOCK:60|RATEGROUP:4|MARKUP:0|CI:197|ACCID:17)
  1470. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [origination_rates]=[ID:8|CODE:^907.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:1|COST:220.00000|INC:60|INITIALBLOCK:60|RATEGROUP:4|MARKUP:0|CI:197|ACCID:17]
  1471. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(execute_on_answer=sched_hangup +1320)
  1472. 2022-06-29 11:31:51.569670 99.07% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [execute_on_answer]=[sched_hangup +1320]
  1473. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(process_cdr=true)
  1474. 2022-06-29 11:31:51.569670 99.07% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [process_cdr]=[true]
  1475. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 sched_hangup(+1320)
  1476. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_scheduler.c:263 Added task 6 switch_ivr_schedule_hangup (a5859f66-b4eb-44b9-aaeb-61a5d3692597) to run at 1656492831
  1477. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_OVERRIDE_CALLERID] Query :SELECT callerid_name as cid_name,callerid_number as cid_number,accountid FROM accounts_callerid WHERE accountid = 17 AND status=0 LIMIT 1
  1478. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(original_caller_id_name=0902)
  1479. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [original_caller_id_name]=[0902]
  1480. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(original_caller_id_number=0902)
  1481. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [original_caller_id_number]=[0902]
  1482. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(presence_data=x|||Dorcas(127718)|||^907.* // Uganda // 220.00000|||MTN // ^90.* // Uganda // 220.00000|||CC)
  1483. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [presence_data]=[x|||Dorcas(127718)|||^907.* // Uganda // 220.00000|||MTN // ^90.* // Uganda // 220.00000|||CC]
  1484. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [GET_LOCALIZATION] Query :SELECT id,out_caller_id_terminate,number_terminate FROM localization WHERE id=(SELECT localization_id from accounts where id = 18) AND status=0 limit 1
  1485. 2022-06-29 11:31:51.569670 99.07% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [DONUMBERTRANSLATION] Before Localization CLI/DST : 90779205097
  1486. 2022-06-29 11:31:51.569670 99.07% [NOTICE] switch_cpp.cpp:1465 [ASTPP] [DONUMBERTRANSLATION] After Localization CLI/DST : 0779205097
  1487. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(termination_rates=ID:6|CODE:^90.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:220.00000|INC:60|TRUNK:3|PROVIDER:18)
  1488. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [termination_rates]=[ID:6|CODE:^90.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:220.00000|INC:60|TRUNK:3|PROVIDER:18]
  1489. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(trunk_id=3)
  1490. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [trunk_id]=[3]
  1491. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(provider_id=18)
  1492. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [provider_id]=[18]
  1493. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 set(hangup_after_bridge=false)
  1494. 2022-06-29 11:31:51.569670 99.07% [DEBUG] mod_dptools.c:1685 SET sofia/default/0902@102.220.200.133 [hangup_after_bridge]=[false]
  1495. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 export(absolute_codec_string=PCMA,G729,PCMA)
  1496. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [absolute_codec_string]=[PCMA,G729,PCMA]
  1497. EXECUTE [depth=0] sofia/default/0902@102.220.200.133 bridge([leg_timeout=0]sofia/gateway/MTN/0779205097)
  1498. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1954 (sofia/default/0902@102.220.200.133) Callstate Change ACTIVE -> RING_WAIT
  1499. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [call_processed]=[internal] to event
  1500. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [callstart]=[2022-06-29 08:31:51] to event
  1501. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [originated_destination_number]=[90779205097] to event
  1502. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [effective_destination_number]=[90779205097] to event
  1503. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [account_id]=[17] to event
  1504. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [account_type]=[0] to event
  1505. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [resellerid]=[0] to event
  1506. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [parent_id]=[0] to event
  1507. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [accountcode]=[127718] to event
  1508. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [call_direction]=[outbound] to event
  1509. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [calltype]=[CALLINGCARD] to event
  1510. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [origination_rates]=[ID:8|CODE:^907.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|CT:1|COST:220.00000|INC:60|INITIALBLOCK:60|RATEGROUP:4|MARKUP:0|CI:197|ACCID:17] to event
  1511. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [original_caller_id_name]=[0902] to event
  1512. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [original_caller_id_number]=[0902] to event
  1513. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [presence_data]=[x|||Dorcas(127718)|||^907.* // Uganda // 220.00000|||MTN // ^90.* // Uganda // 220.00000|||CC] to event
  1514. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [termination_rates]=[ID:6|CODE:^90.*|DESTINATION:Uganda|CONNECTIONCOST:0.00000|INCLUDEDSECONDS:0|COST:220.00000|INC:60|TRUNK:3|PROVIDER:18] to event
  1515. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [trunk_id]=[3] to event
  1516. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [provider_id]=[18] to event
  1517. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_channel.c:1269 sofia/default/0902@102.220.200.133 EXPORTING[export_vars] [absolute_codec_string]=[PCMA,G729,PCMA] to event
  1518. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
  1519. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_ivr_originate.c:2843 Parsing session specific variables
  1520. 2022-06-29 11:31:51.569670 99.07% [NOTICE] switch_channel.c:1123 New Channel sofia/default/0779205097 [6cd8f3ac-5e22-479b-b59e-cd0856576536]
  1521. 2022-06-29 11:31:51.569670 99.07% [DEBUG] mod_sofia.c:5121 (sofia/default/0779205097) State Change CS_NEW -> CS_INIT
  1522. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0779205097) Running State Change CS_INIT (Cur 2 Tot 709)
  1523. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:624 (sofia/default/0779205097) State INIT
  1524. 2022-06-29 11:31:51.569670 99.07% [DEBUG] mod_sofia.c:97 sofia/default/0779205097 SOFIA INIT
  1525. 2022-06-29 11:31:51.569670 99.07% [INFO] sofia_glue.c:1651 sofia/default/0779205097 sending invite call-id: (null)
  1526. 2022-06-29 11:31:51.569670 99.07% [DEBUG] sofia_glue.c:1654 sofia/default/0779205097 sending invite version: 1.10.7 -release-19-883d2cb662 64bit
  1527. Local SDP:
  1528. v=0
  1529. o=FreeSWITCH 1656466345 1656466346 IN IP4 102.220.200.133
  1530. s=FreeSWITCH
  1531. c=IN IP4 102.220.200.133
  1532. t=0 0
  1533. m=audio 25166 RTP/AVP 8 18 101
  1534. a=rtpmap:8 PCMA/8000
  1535. a=rtpmap:18 G729/8000
  1536. a=rtpmap:101 telephone-event/8000
  1537. a=fmtp:101 0-15
  1538. a=ptime:20
  1539. a=sendrecv
  1540.  
  1541. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:40 sofia/default/0779205097 Standard INIT
  1542. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:48 (sofia/default/0779205097) State Change CS_INIT -> CS_ROUTING
  1543. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:624 (sofia/default/0779205097) State INIT going to sleep
  1544. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0779205097) Running State Change CS_ROUTING (Cur 2 Tot 709)
  1545. 2022-06-29 11:31:51.569670 99.07% [DEBUG] sofia.c:7499 Channel sofia/default/0779205097 entering state [calling][0]
  1546. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:640 (sofia/default/0779205097) State ROUTING
  1547. 2022-06-29 11:31:51.569670 99.07% [DEBUG] mod_sofia.c:158 sofia/default/0779205097 SOFIA ROUTING
  1548. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_ivr_originate.c:67 (sofia/default/0779205097) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  1549. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:640 (sofia/default/0779205097) State ROUTING going to sleep
  1550. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0779205097) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 709)
  1551. 2022-06-29 11:31:51.569670 99.07% [DEBUG] sofia.c:7499 Channel sofia/default/0779205097 entering state [terminated][503]
  1552. 2022-06-29 11:31:51.569670 99.07% [NOTICE] sofia.c:8738 Hangup sofia/default/0779205097 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE]
  1553. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:659 (sofia/default/0779205097) State CONSUME_MEDIA
  1554. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:659 (sofia/default/0779205097) State CONSUME_MEDIA going to sleep
  1555. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0779205097) Running State Change CS_HANGUP (Cur 2 Tot 709)
  1556. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:844 (sofia/default/0779205097) Callstate Change DOWN -> HANGUP
  1557. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:846 (sofia/default/0779205097) State HANGUP
  1558. 2022-06-29 11:31:51.569670 99.07% [DEBUG] mod_sofia.c:468 Channel sofia/default/0779205097 hanging up, cause: NORMAL_TEMPORARY_FAILURE
  1559. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:59 sofia/default/0779205097 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
  1560. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:846 (sofia/default/0779205097) State HANGUP going to sleep
  1561. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:616 (sofia/default/0779205097) State Change CS_HANGUP -> CS_REPORTING
  1562. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0779205097) Running State Change CS_REPORTING (Cur 2 Tot 709)
  1563. 2022-06-29 11:31:51.569670 99.07% [DEBUG] switch_core_state_machine.c:932 (sofia/default/0779205097) State REPORTING
  1564. 2022-06-29 11:31:51.569670 99.07% [INFO] mod_json_cdr.c:271 Process [6cd8f3ac-5e22-479b-b59e-cd0856576536.cdr.json]
  1565. 2022-06-29 11:31:51.589613 99.07% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE]
  1566. 2022-06-29 11:31:51.589613 99.07% [DEBUG] switch_channel.c:2178 (sofia/default/0902@102.220.200.133) Callstate Change RING_WAIT -> ACTIVE
  1567. 2022-06-29 11:31:51.589613 99.07% [INFO] mod_dptools.c:3653 Originate Failed.  Cause: NORMAL_TEMPORARY_FAILURE
  1568. 2022-06-29 11:31:51.589613 99.07% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-callingcard-menu.wav sample rate 16000 doesn't match requested rate 8000
  1569. 2022-06-29 11:31:51.589613 99.07% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  1570. 2022-06-29 11:31:51.649679 99.00% [DEBUG] switch_core_state_machine.c:168 sofia/default/0779205097 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
  1571. 2022-06-29 11:31:51.649679 99.00% [DEBUG] switch_core_state_machine.c:932 (sofia/default/0779205097) State REPORTING going to sleep
  1572. 2022-06-29 11:31:51.649679 99.00% [DEBUG] switch_core_state_machine.c:607 (sofia/default/0779205097) State Change CS_REPORTING -> CS_DESTROY
  1573. 2022-06-29 11:31:51.649679 99.00% [DEBUG] switch_core_session.c:1753 Session 709 (sofia/default/0779205097) Locked, Waiting on external entities
  1574. 2022-06-29 11:31:51.649679 99.00% [NOTICE] switch_core_session.c:1771 Session 709 (sofia/default/0779205097) Ended
  1575. 2022-06-29 11:31:51.649679 99.00% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/0779205097 [CS_DESTROY]
  1576. 2022-06-29 11:31:51.649679 99.00% [DEBUG] switch_core_state_machine.c:735 (sofia/default/0779205097) Running State Change CS_DESTROY (Cur 1 Tot 709)
  1577. 2022-06-29 11:31:51.649679 99.00% [DEBUG] switch_core_state_machine.c:745 (sofia/default/0779205097) State DESTROY
  1578. 2022-06-29 11:31:51.649679 99.00% [DEBUG] mod_sofia.c:379 sofia/default/0779205097 SOFIA DESTROY
  1579. 2022-06-29 11:31:51.649679 99.00% [DEBUG] switch_core_state_machine.c:175 sofia/default/0779205097 Standard DESTROY
  1580. 2022-06-29 11:31:51.649679 99.00% [DEBUG] switch_core_state_machine.c:745 (sofia/default/0779205097) State DESTROY going to sleep
  1581. 2022-06-29 11:31:57.669694 98.47% [DEBUG] switch_rtp.c:8179 RTP RECV DTMF 3:1040
  1582. 2022-06-29 11:31:57.669694 98.47% [INFO] switch_channel.c:527 RECV DTMF 3:1040
  1583. 2022-06-29 11:31:57.689639 98.47% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-callingcard-menu.wav
  1584. 2022-06-29 11:31:57.689639 98.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Got DTMF digits: 3retries:0
  1585. 2022-06-29 11:31:57.689639 98.47% [DEBUG] switch_core_file.c:444 File /usr/share/freeswitch/sounds/en/us/callie/astpp-goodbye.wav sample rate 16000 doesn't match requested rate 8000
  1586. 2022-06-29 11:31:57.689639 98.47% [DEBUG] switch_ivr_play_say.c:1556 Codec Activated L16@8000hz 1 channels 30ms
  1587. 2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_ivr_play_say.c:2001 done playing file /usr/share/freeswitch/sounds/en/us/callie/astpp-goodbye.wav
  1588. 2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_cpp.cpp:749 CoreSession::hangup
  1589. 2022-06-29 11:31:58.489662 98.47% [NOTICE] switch_cpp.cpp:751 Hangup sofia/default/0902@102.220.200.133 [CS_EXECUTE] [NORMAL_CLEARING]
  1590. 2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Got DTMF digits: retries:1
  1591. 2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Got DTMF digits: retries:2
  1592. 2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_cpp.cpp:749 CoreSession::hangup
  1593. 2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_cpp.cpp:1209 sofia/default/0902@102.220.200.133 destroy/unlink session from object
  1594. 2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_session.c:2983 sofia/default/0902@102.220.200.133 skip receive message [PHONE_EVENT] (channel is hungup already)
  1595. 2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:647 (sofia/default/0902@102.220.200.133) State EXECUTE going to sleep
  1596. 2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_HANGUP (Cur 1 Tot 709)
  1597. 2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:844 (sofia/default/0902@102.220.200.133) Callstate Change ACTIVE -> HANGUP
  1598. 2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:846 (sofia/default/0902@102.220.200.133) State HANGUP
  1599. 2022-06-29 11:31:58.489662 98.47% [DEBUG] mod_sofia.c:462 sofia/default/0902@102.220.200.133 Overriding SIP cause 480 with 503 from the other leg
  1600. 2022-06-29 11:31:58.489662 98.47% [DEBUG] mod_sofia.c:468 Channel sofia/default/0902@102.220.200.133 hanging up, cause: NORMAL_CLEARING
  1601. 2022-06-29 11:31:58.489662 98.47% [DEBUG] mod_sofia.c:522 Sending BYE to sofia/default/0902@102.220.200.133
  1602. 2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:59 sofia/default/0902@102.220.200.133 Standard HANGUP, cause: NORMAL_CLEARING
  1603. 2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:846 (sofia/default/0902@102.220.200.133) State HANGUP going to sleep
  1604. 2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:616 (sofia/default/0902@102.220.200.133) State Change CS_HANGUP -> CS_REPORTING
  1605. 2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:581 (sofia/default/0902@102.220.200.133) Running State Change CS_REPORTING (Cur 1 Tot 709)
  1606. 2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:932 (sofia/default/0902@102.220.200.133) State REPORTING
  1607. 2022-06-29 11:31:58.489662 98.47% [INFO] mod_json_cdr.c:271 Process [a5859f66-b4eb-44b9-aaeb-61a5d3692597.cdr.json]
  1608. 2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:168 sofia/default/0902@102.220.200.133 Standard REPORTING, cause: NORMAL_CLEARING
  1609. 2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:932 (sofia/default/0902@102.220.200.133) State REPORTING going to sleep
  1610. 2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:607 (sofia/default/0902@102.220.200.133) State Change CS_REPORTING -> CS_DESTROY
  1611. 2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_session.c:1753 Session 708 (sofia/default/0902@102.220.200.133) Locked, Waiting on external entities
  1612. 2022-06-29 11:31:58.489662 98.47% [NOTICE] switch_core_session.c:1771 Session 708 (sofia/default/0902@102.220.200.133) Ended
  1613. 2022-06-29 11:31:58.489662 98.47% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/0902@102.220.200.133 [CS_DESTROY]
  1614. 2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:735 (sofia/default/0902@102.220.200.133) Running State Change CS_DESTROY (Cur 0 Tot 709)
  1615. 2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:745 (sofia/default/0902@102.220.200.133) State DESTROY
  1616. 2022-06-29 11:31:58.489662 98.47% [DEBUG] mod_sofia.c:379 sofia/default/0902@102.220.200.133 SOFIA DESTROY
  1617. 2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:175 sofia/default/0902@102.220.200.133 Standard DESTROY
  1618. 2022-06-29 11:31:58.489662 98.47% [DEBUG] switch_core_state_machine.c:745 (sofia/default/0902@102.220.200.133) State DESTROY going to sleep
  1619. 2022-06-29 11:31:58.569698 98.47% [DEBUG] switch_scheduler.c:147 Deleting task 6 switch_ivr_schedule_hangup (a5859f66-b4eb-44b9-aaeb-61a5d3692597)
  1620. 2022-06-29 11:32:05.209690 97.73% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [670@102.220.200.133] from ip 103.219.21.17
  1621. 2022-06-29 11:32:37.369662 99.13% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [769@102.220.200.133] from ip 89.37.173.54
  1622. 2022-06-29 11:32:42.809696 99.27% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [691@102.220.200.133] from ip 62.197.144.11
  1623. 2022-06-29 11:32:43.009695 99.27% [WARNING] sofia_reg.c:3223 Can't find user [691@102.220.200.133] from 62.197.144.11
  1624. You must define a domain called '102.220.200.133' in your directory and add a user with the id="691" attribute
  1625. and you must configure your device to use the proper domain in its authentication credentials.
  1626. 2022-06-29 11:32:43.009695 99.27% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [691@102.220.200.133] from ip 62.197.144.11
  1627. 2022-06-29 11:32:44.649694 99.23% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [3382@102.220.200.133] from ip 85.14.245.202
  1628. 2022-06-29 11:33:01.589657 99.27% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [763@102.220.200.133] from ip 194.169.170.4
  1629. 2022-06-29 11:33:11.789691 98.13% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [771@102.220.200.133] from ip 143.244.42.104
  1630. 2022-06-29 11:33:12.209642 98.13% [WARNING] sofia_reg.c:3223 Can't find user [771@102.220.200.133] from 143.244.42.104
  1631. You must define a domain called '102.220.200.133' in your directory and add a user with the id="771" attribute
  1632. and you must configure your device to use the proper domain in its authentication credentials.
  1633. 2022-06-29 11:33:12.209642 98.13% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [771@102.220.200.133] from ip 143.244.42.104
  1634. 2022-06-29 11:33:25.369699 98.03% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [770@102.220.200.133] from ip 62.197.156.4
  1635. 2022-06-29 11:33:26.009635 98.13% [WARNING] sofia_reg.c:3223 Can't find user [770@102.220.200.133] from 62.197.156.4
  1636. You must define a domain called '102.220.200.133' in your directory and add a user with the id="770" attribute
  1637. and you must configure your device to use the proper domain in its authentication credentials.
  1638. 2022-06-29 11:33:26.009635 98.13% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [770@102.220.200.133] from ip 62.197.156.4
  1639. 2022-06-29 11:33:26.989695 98.23% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [768@102.220.200.133] from ip 45.136.155.56
  1640. 2022-06-29 11:33:27.409696 98.23% [WARNING] sofia_reg.c:3223 Can't find user [768@102.220.200.133] from 45.136.155.56
  1641. You must define a domain called '102.220.200.133' in your directory and add a user with the id="768" attribute
  1642. and you must configure your device to use the proper domain in its authentication credentials.
  1643. 2022-06-29 11:33:27.409696 98.23% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [768@102.220.200.133] from ip 45.136.155.56
  1644. 2022-06-29 11:33:47.689698 99.33% [WARNING] sofia_reg.c:1861 SIP auth challenge (REGISTER) on sofia profile 'default' for [670@102.220.200.133] from ip 146.70.102.190
  1645. 2022-06-29 11:33:48.229696 99.33% [WARNING] sofia_reg.c:3223 Can't find user [670@102.220.200.133] from 146.70.102.190
  1646. You must define a domain called '102.220.200.133' in your directory and add a user with the id="670" attribute
  1647. and you must configure your device to use the proper domain in its authentication credentials.
  1648. 2022-06-29 11:33:48.229696 99.33% [WARNING] sofia_reg.c:1806 SIP auth failure (REGISTER) on sofia profile 'default' for [670@102.220.200.133] from ip 146.70.102.190
  1649. freeswitc

Reply to "Freeswitch-logs"