From Prashant Kumar, 1 Year ago, written in FreeSWITCH.
- view diff
Embed
  1. freeswitch@FS1ClusterQA>
  2. freeswitch@FS1ClusterQA>
  3. freeswitch@FS1ClusterQA>
  4. freeswitch@FS1ClusterQA>
  5. 2023-11-10 03:58:32.274356 91.10% [NOTICE] switch_channel.c:1123 New Channel sofia/default/9000100044@cluster.astppbilling.org:5073 [8d73be50-47b0-4206-ab18-e79df024803c]
  6. 2023-11-10 03:58:32.274356 91.10% [DEBUG] switch_core_state_machine.c:581 (sofia/default/9000100044@cluster.astppbilling.org:5073) Running State Change CS_NEW (Cur 1 Tot 12570)
  7. 2023-11-10 03:58:32.274356 91.10% [INFO] sofia.c:10462 sofia/default/9000100044@cluster.astppbilling.org:5073 receiving invite from 78.47.101.152:5073 version: 1.10.7 -release 64bit call-id: DLGCH_ATQ3AgkdO2ACNCBaHiMeOQIdLBQdDh1iADcgXQkeHWIBNzMFHQ0WPgEaJEA-
  8. 2023-11-10 03:58:32.274356 91.10% [DEBUG] sofia.c:10556 verifying acl "default" for ip/port 78.47.101.152:0.
  9. 2023-11-10 03:58:32.274356 91.10% [DEBUG] sofia.c:10585 IP 78.47.101.152 Approved by acl "default[]". Access Granted.
  10. 2023-11-10 03:58:32.274356 91.10% [DEBUG] sofia.c:7499 Channel sofia/default/9000100044@cluster.astppbilling.org:5073 entering state [received][100]
  11. 2023-11-10 03:58:32.274356 91.10% [DEBUG] sofia.c:7509 Remote SDP:
  12. v=0
  13. o=Z 0 0 IN IP4 78.47.101.152
  14. s=Z
  15. c=IN IP4 78.47.101.152
  16. t=0 0
  17. m=audio 35130 RTP/AVP 3 110 8 0 98 101
  18. a=rtpmap:3 GSM/8000
  19. a=rtpmap:110 speex/8000
  20. a=rtpmap:8 PCMA/8000
  21. a=rtpmap:0 PCMU/8000
  22. a=rtpmap:98 iLBC/8000
  23. a=fmtp:98 mode=20
  24. a=rtpmap:101 telephone-event/8000
  25. a=fmtp:101 0-15
  26. a=rtcp:35131
  27.  
  28. 2023-11-10 03:58:32.274356 91.10% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
  29. 2023-11-10 03:58:32.274356 91.10% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
  30. 2023-11-10 03:58:32.274356 91.10% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [speex:110:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
  31. 2023-11-10 03:58:32.274356 91.10% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [speex:110:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
  32. 2023-11-10 03:58:32.274356 91.10% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  33. 2023-11-10 03:58:32.274356 91.10% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  34. 2023-11-10 03:58:32.274356 91.10% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  35. 2023-11-10 03:58:32.274356 91.10% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  36. 2023-11-10 03:58:32.274356 91.10% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  37. 2023-11-10 03:58:32.274356 91.10% [DEBUG] switch_core_media.c:5705 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  38. 2023-11-10 03:58:32.274356 91.10% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [iLBC:98:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
  39. 2023-11-10 03:58:32.274356 91.10% [DEBUG] switch_core_media.c:5650 Audio Codec Compare [iLBC:98:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
  40. 2023-11-10 03:58:32.274356 91.10% [DEBUG] switch_core_media.c:5566 Set telephone-event payload to 101@8000
  41. 2023-11-10 03:58:32.274356 91.10% [DEBUG] switch_core_media.c:3870 Set Codec sofia/default/9000100044@cluster.astppbilling.org:5073 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
  42. 2023-11-10 03:58:32.274356 91.10% [DEBUG] switch_core_codec.c:111 sofia/default/9000100044@cluster.astppbilling.org:5073 Original read codec set to PCMA:8
  43. 2023-11-10 03:58:32.274356 91.10% [DEBUG] switch_core_media.c:5915 Set telephone-event payload to 101@8000
  44. 2023-11-10 03:58:32.274356 91.10% [DEBUG] switch_core_media.c:5973 sofia/default/9000100044@cluster.astppbilling.org:5073 Set 2833 dtmf send payload to 101 recv payload to 101
  45. 2023-11-10 03:58:32.274356 91.10% [DEBUG] sofia.c:7933 (sofia/default/9000100044@cluster.astppbilling.org:5073) State Change CS_NEW -> CS_INIT
  46. 2023-11-10 03:58:32.274356 91.10% [DEBUG] switch_core_state_machine.c:600 (sofia/default/9000100044@cluster.astppbilling.org:5073) State NEW
  47. 2023-11-10 03:58:32.274356 91.10% [DEBUG] switch_core_state_machine.c:581 (sofia/default/9000100044@cluster.astppbilling.org:5073) Running State Change CS_INIT (Cur 1 Tot 12570)
  48. 2023-11-10 03:58:32.274356 91.10% [DEBUG] switch_core_state_machine.c:624 (sofia/default/9000100044@cluster.astppbilling.org:5073) State INIT
  49. 2023-11-10 03:58:32.274356 91.10% [DEBUG] mod_sofia.c:97 sofia/default/9000100044@cluster.astppbilling.org:5073 SOFIA INIT
  50. 2023-11-10 03:58:32.274356 91.10% [DEBUG] switch_core_state_machine.c:40 sofia/default/9000100044@cluster.astppbilling.org:5073 Standard INIT
  51. 2023-11-10 03:58:32.274356 91.10% [DEBUG] switch_core_state_machine.c:48 (sofia/default/9000100044@cluster.astppbilling.org:5073) State Change CS_INIT -> CS_ROUTING
  52. 2023-11-10 03:58:32.274356 91.10% [DEBUG] switch_core_state_machine.c:624 (sofia/default/9000100044@cluster.astppbilling.org:5073) State INIT going to sleep
  53. 2023-11-10 03:58:32.274356 91.10% [DEBUG] switch_core_state_machine.c:581 (sofia/default/9000100044@cluster.astppbilling.org:5073) Running State Change CS_ROUTING (Cur 1 Tot 12570)
  54. 2023-11-10 03:58:32.274356 91.10% [DEBUG] switch_channel.c:2380 (sofia/default/9000100044@cluster.astppbilling.org:5073) Callstate Change DOWN -> RINGING
  55. 2023-11-10 03:58:32.274356 91.10% [DEBUG] switch_core_state_machine.c:640 (sofia/default/9000100044@cluster.astppbilling.org:5073) State ROUTING
  56. 2023-11-10 03:58:32.274356 91.10% [DEBUG] mod_sofia.c:158 sofia/default/9000100044@cluster.astppbilling.org:5073 SOFIA ROUTING
  57. 2023-11-10 03:58:32.274356 91.10% [DEBUG] switch_core_state_machine.c:230 sofia/default/9000100044@cluster.astppbilling.org:5073 Standard ROUTING
  58. 2023-11-10 03:58:32.274356 91.10% [INFO] mod_dialplan_xml.c:639 Processing 9000100044 <9000100044>->1234 in context default
  59. 2023-11-10 03:58:32.294323 91.10% [INFO] switch_cpp.cpp:1465 [ASTPP] CACHE FAIL
  60. 2023-11-10 03:58:32.294323 91.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_SYSTEM]1.0
  61. 2023-11-10 03:58:32.294323 91.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM `system` WHERE group_title IN ('global','opensips','callingcard','calls','international_prefixes','interconnect_code')
  62. 2023-11-10 03:58:32.294323 91.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
  63. 2023-11-10 03:58:32.334321 91.10% [INFO] switch_cpp.cpp:1465 [ASTPP] [feature_code_call_transfer] Blind Call Flag: 0
  64. 2023-11-10 03:58:32.334321 91.10% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] Dialed number : 1234
  65. 2023-11-10 03:58:32.334321 91.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CHECK_FEATURE_CODE] Query :SELECT id,feature_action,feature_code from feature_code where feature_code = '1234' limit 1
  66. 2023-11-10 03:58:32.334321 91.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [DOAUTHORIZATION] Query :SELECT access_number FROM accessnumber WHERE access_number = '1234' AND status=0 limit 1
  67. 2023-11-10 03:58:32.334321 91.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [Functions] [Fifo Condition Check] Query :SELECT id,destination_number,agent_hold_file from pbx_queue WHERE destination_number = '1234' and status=0 LIMIT 1
  68. 2023-11-10 03:58:32.334321 91.10% [INFO] switch_cpp.cpp:1465 [ASTPP] [PBX] queue_destination_number,agent_hold_file : 1234
  69. 2023-11-10 03:58:32.334321 91.10% [WARNING] switch_cpp.cpp:1465 [ASTPP] Fifo Agent Flag1
  70. 2023-11-10 03:58:32.334321 91.10% [INFO] switch_cpp.cpp:1465 [ASTPP] [PBX] Queue Destination Number : 1234
  71. 2023-11-10 03:58:32.334321 91.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [Functions] [GET_RING_GROUP_INFO] Query :SELECT file_name from pbx_recording WHERE id = '${be-ring}' LIMIT 1
  72. 2023-11-10 03:58:32.334321 91.10% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Generated XML:
  73. <?xml version="1.0" encoding="UTF-8" standalone="no"?>
  74. <document type="freeswitch/xml">
  75. <section name="dialplan" description="ASTPP Dialplan">
  76. <context name="default">
  77. <extension name="1234">
  78. <condition field="destination_number" expression="1234">
  79. <action application="export" data="did_user_domain=cluster.astppbilling.org"/>
  80. <action application="set" data="fifo_music=${be-ring}"/>
  81. <action application="set" data="fifo_music=$${hold_music}"/>
  82.     <action application="answer"/>
  83.     <action application="fifo" data="myqueue_1 out wait"/>
  84. </condition>
  85. </extension>
  86. </context>
  87. </section>
  88. </document>
  89. Dialplan: sofia/default/9000100044@cluster.astppbilling.org:5073 parsing [default->1234] continue=false
  90. Dialplan: sofia/default/9000100044@cluster.astppbilling.org:5073 Regex (PASS) [1234] destination_number(1234) =~ /1234/ break=on-false
  91. Dialplan: sofia/default/9000100044@cluster.astppbilling.org:5073 Action export(did_user_domain=cluster.astppbilling.org)
  92. Dialplan: sofia/default/9000100044@cluster.astppbilling.org:5073 Action set(fifo_music=${be-ring})
  93. Dialplan: sofia/default/9000100044@cluster.astppbilling.org:5073 Action set(fifo_music=$${hold_music})
  94. Dialplan: sofia/default/9000100044@cluster.astppbilling.org:5073 Action answer()
  95. Dialplan: sofia/default/9000100044@cluster.astppbilling.org:5073 Action fifo(myqueue_1 out wait)
  96. 2023-11-10 03:58:32.334321 91.10% [DEBUG] switch_core_state_machine.c:281 (sofia/default/9000100044@cluster.astppbilling.org:5073) State Change CS_ROUTING -> CS_EXECUTE
  97. 2023-11-10 03:58:32.334321 91.10% [DEBUG] switch_core_state_machine.c:640 (sofia/default/9000100044@cluster.astppbilling.org:5073) State ROUTING going to sleep
  98. 2023-11-10 03:58:32.334321 91.10% [DEBUG] switch_core_state_machine.c:581 (sofia/default/9000100044@cluster.astppbilling.org:5073) Running State Change CS_EXECUTE (Cur 1 Tot 12570)
  99. 2023-11-10 03:58:32.334321 91.10% [DEBUG] switch_core_state_machine.c:647 (sofia/default/9000100044@cluster.astppbilling.org:5073) State EXECUTE
  100. 2023-11-10 03:58:32.334321 91.10% [DEBUG] mod_sofia.c:213 sofia/default/9000100044@cluster.astppbilling.org:5073 SOFIA EXECUTE
  101. 2023-11-10 03:58:32.334321 91.10% [DEBUG] switch_core_state_machine.c:323 sofia/default/9000100044@cluster.astppbilling.org:5073 Standard EXECUTE
  102. EXECUTE [depth=0] sofia/default/9000100044@cluster.astppbilling.org:5073 export(did_user_domain=cluster.astppbilling.org)
  103. 2023-11-10 03:58:32.334321 91.10% [DEBUG] switch_channel.c:1315 EXPORT (export_vars) [did_user_domain]=[cluster.astppbilling.org]
  104. EXECUTE [depth=0] sofia/default/9000100044@cluster.astppbilling.org:5073 set(fifo_music=%(1000,3000,425))
  105. 2023-11-10 03:58:32.334321 91.10% [DEBUG] mod_dptools.c:1685 SET sofia/default/9000100044@cluster.astppbilling.org:5073 [fifo_music]=[%(1000,3000,425)]
  106. EXECUTE [depth=0] sofia/default/9000100044@cluster.astppbilling.org:5073 set(fifo_music=local_stream://moh)
  107. 2023-11-10 03:58:32.354313 91.10% [DEBUG] mod_dptools.c:1685 SET sofia/default/9000100044@cluster.astppbilling.org:5073 [fifo_music]=[local_stream://moh]
  108. EXECUTE [depth=0] sofia/default/9000100044@cluster.astppbilling.org:5073 answer()
  109. 2023-11-10 03:58:32.354313 91.10% [DEBUG] switch_core_media.c:8777 AUDIO RTP [sofia/default/9000100044@cluster.astppbilling.org:5073] 167.235.194.5 port 28776 -> 78.47.101.152 port 35130 codec: 8 ms: 20
  110. 2023-11-10 03:58:32.354313 91.10% [DEBUG] switch_rtp.c:4619 Starting timer [soft] 160 bytes per 20ms
  111. 2023-11-10 03:58:32.354313 91.10% [DEBUG] switch_core_media.c:8997 Activating RTCP PORT 35131
  112. 2023-11-10 03:58:32.354313 91.10% [DEBUG] switch_rtp.c:5017 RTCP send rate is: 1000 and packet rate is: 20000 Remote Port: 35131
  113. 2023-11-10 03:58:32.354313 91.10% [DEBUG] switch_rtp.c:2776 Setting RTCP remote addr to 78.47.101.152:35131 2
  114. 2023-11-10 03:58:32.354313 91.10% [DEBUG] switch_core_media.c:9089 sofia/default/9000100044@cluster.astppbilling.org:5073 Set 2833 dtmf send payload to 101
  115. 2023-11-10 03:58:32.354313 91.10% [DEBUG] switch_core_media.c:9096 sofia/default/9000100044@cluster.astppbilling.org:5073 Set 2833 dtmf receive payload to 101
  116. 2023-11-10 03:58:32.354313 91.10% [DEBUG] switch_core_media.c:9119 sofia/default/9000100044@cluster.astppbilling.org:5073 Set rtp dtmf delay to 40
  117. 2023-11-10 03:58:32.354313 91.10% [DEBUG] mod_sofia.c:913 Local SDP sofia/default/9000100044@cluster.astppbilling.org:5073:
  118. v=0
  119. o=FreeSWITCH 1699559936 1699559937 IN IP4 167.235.194.5
  120. s=FreeSWITCH
  121. c=IN IP4 167.235.194.5
  122. t=0 0
  123. m=audio 28776 RTP/AVP 8 101
  124. a=rtpmap:8 PCMA/8000
  125. a=rtpmap:101 telephone-event/8000
  126. a=fmtp:101 0-15
  127. a=ptime:20
  128. a=sendrecv
  129. a=rtcp:28777 IN IP4 167.235.194.5
  130.  
  131. 2023-11-10 03:58:32.354313 91.10% [NOTICE] mod_dptools.c:1419 Channel [sofia/default/9000100044@cluster.astppbilling.org:5073] has been answered
  132. 2023-11-10 03:58:32.354313 91.10% [DEBUG] switch_channel.c:3950 (sofia/default/9000100044@cluster.astppbilling.org:5073) Callstate Change RINGING -> ACTIVE
  133. 2023-11-10 03:58:32.354313 91.10% [DEBUG] sofia.c:7499 Channel sofia/default/9000100044@cluster.astppbilling.org:5073 entering state [completed][200]
  134. 2023-11-10 03:58:32.354313 91.10% [ERR] switch_core_session.c:2770 Invalid Application fifo
  135. 2023-11-10 03:58:32.354313 91.10% [NOTICE] switch_core_session.c:2771 Hangup sofia/default/9000100044@cluster.astppbilling.org:5073 [CS_EXECUTE] [DESTINATION_OUT_OF_ORDER]
  136. 2023-11-10 03:58:32.354313 91.10% [DEBUG] switch_core_state_machine.c:647 (sofia/default/9000100044@cluster.astppbilling.org:5073) State EXECUTE going to sleep
  137. 2023-11-10 03:58:32.354313 91.10% [DEBUG] switch_core_state_machine.c:581 (sofia/default/9000100044@cluster.astppbilling.org:5073) Running State Change CS_HANGUP (Cur 1 Tot 12570)
  138. 2023-11-10 03:58:32.354313 91.10% [DEBUG] switch_channel.c:3990 sofia/default/9000100044@cluster.astppbilling.org:5073 skip receive message [VIDEO_SYNC] (channel is hungup already)
  139. 2023-11-10 03:58:32.354313 91.10% [DEBUG] switch_core_state_machine.c:844 (sofia/default/9000100044@cluster.astppbilling.org:5073) Callstate Change ACTIVE -> HANGUP
  140. 2023-11-10 03:58:32.354313 91.10% [DEBUG] switch_core_state_machine.c:846 (sofia/default/9000100044@cluster.astppbilling.org:5073) State HANGUP
  141. 2023-11-10 03:58:32.354313 91.10% [DEBUG] mod_sofia.c:468 Channel sofia/default/9000100044@cluster.astppbilling.org:5073 hanging up, cause: DESTINATION_OUT_OF_ORDER
  142. 2023-11-10 03:58:32.354313 91.10% [DEBUG] mod_sofia.c:522 Sending BYE to sofia/default/9000100044@cluster.astppbilling.org:5073
  143. 2023-11-10 03:58:32.354313 91.10% [DEBUG] switch_core_state_machine.c:59 sofia/default/9000100044@cluster.astppbilling.org:5073 Standard HANGUP, cause: DESTINATION_OUT_OF_ORDER
  144. 2023-11-10 03:58:32.354313 91.10% [DEBUG] switch_core_state_machine.c:846 (sofia/default/9000100044@cluster.astppbilling.org:5073) State HANGUP going to sleep
  145. 2023-11-10 03:58:32.354313 91.10% [DEBUG] switch_core_state_machine.c:616 (sofia/default/9000100044@cluster.astppbilling.org:5073) State Change CS_HANGUP -> CS_REPORTING
  146. 2023-11-10 03:58:32.354313 91.10% [DEBUG] switch_core_state_machine.c:581 (sofia/default/9000100044@cluster.astppbilling.org:5073) Running State Change CS_REPORTING (Cur 1 Tot 12570)
  147. 2023-11-10 03:58:32.354313 91.10% [DEBUG] switch_core_state_machine.c:932 (sofia/default/9000100044@cluster.astppbilling.org:5073) State REPORTING
  148. 2023-11-10 03:58:32.354313 91.10% [INFO] mod_json_cdr.c:271 Process [8d73be50-47b0-4206-ab18-e79df024803c.cdr.json]
  149. 2023-11-10 03:58:32.374354 91.10% [DEBUG] switch_core_state_machine.c:168 sofia/default/9000100044@cluster.astppbilling.org:5073 Standard REPORTING, cause: DESTINATION_OUT_OF_ORDER
  150. 2023-11-10 03:58:32.374354 91.10% [DEBUG] switch_core_state_machine.c:932 (sofia/default/9000100044@cluster.astppbilling.org:5073) State REPORTING going to sleep
  151. 2023-11-10 03:58:32.374354 91.10% [DEBUG] switch_core_state_machine.c:607 (sofia/default/9000100044@cluster.astppbilling.org:5073) State Change CS_REPORTING -> CS_DESTROY
  152. 2023-11-10 03:58:32.374354 91.10% [DEBUG] switch_core_session.c:1753 Session 12570 (sofia/default/9000100044@cluster.astppbilling.org:5073) Locked, Waiting on external entities
  153. 2023-11-10 03:58:32.374354 91.10% [NOTICE] switch_core_session.c:1771 Session 12570 (sofia/default/9000100044@cluster.astppbilling.org:5073) Ended
  154. 2023-11-10 03:58:32.374354 91.10% [NOTICE] switch_core_session.c:1775 Close Channel sofia/default/9000100044@cluster.astppbilling.org:5073 [CS_DESTROY]
  155. 2023-11-10 03:58:32.374354 91.10% [DEBUG] switch_core_state_machine.c:735 (sofia/default/9000100044@cluster.astppbilling.org:5073) Running State Change CS_DESTROY (Cur 0 Tot 12570)
  156. 2023-11-10 03:58:32.374354 91.10% [DEBUG] switch_core_state_machine.c:745 (sofia/default/9000100044@cluster.astppbilling.org:5073) State DESTROY
  157. 2023-11-10 03:58:32.374354 91.10% [DEBUG] mod_sofia.c:379 sofia/default/9000100044@cluster.astppbilling.org:5073 SOFIA DESTROY
  158. 2023-11-10 03:58:32.374354 91.10% [DEBUG] switch_core_state_machine.c:175 sofia/default/9000100044@cluster.astppbilling.org:5073 Standard DESTROY
  159. 2023-11-10 03:58:32.374354 91.10% [DEBUG] switch_core_state_machine.c:745 (sofia/default/9000100044@cluster.astppbilling.org:5073) State DESTROY going to sleep
  160. Type control-D or /exit or /quit or /bye to exit.
  161.  
  162. freeswitch@FS1ClusterQA>
  163. freeswitch@FS1ClusterQA>
  164. freeswitch@FS1ClusterQA>
  165. freeswitch@FS1ClusterQA>
  166. freeswitch@FS1ClusterQA>
  167. freeswitch@FS1ClusterQA>
  168. freeswitch@FS1ClusterQA>
  169. freeswitch@FS1ClusterQA> /exit
  170.