From Prashant Kumar, 5 Months ago, written in FreeSWITCH.
- view diff
Embed
  1. span style="color: cornflowerblue; font-weight: bold;"> 2023-12-12 05:59:51.473192 96.53% [NOTICE] switch_channel.c:1142 New Channel sofia/default/90678@automation3betav601.astppbilling.org:5071 [cc368a8c-2cd9-4e10-a5d0-653df1d76675]
  2. 2023-12-12 05:59:51.473192 96.53% [DEBUG] switch_core_state_machine.c:581 (sofia/default/90678@automation3betav601.astppbilling.org:5071) Running State Change CS_NEW (Cur 3 Tot 27)
  3. 2023-12-12 05:59:51.473192 96.53% [INFO] sofia.c:10459 sofia/default/90678@automation3betav601.astppbilling.org:5071 receiving invite from 106.216.115.55:54068 version: 1.10.10-release  64bit call-id: NmM4NDUxOTQzYzZiMWUzMmE2OWMzYzliM2ZmZDVmODk.
  4. 2023-12-12 05:59:51.473192 96.53% [DEBUG] sofia.c:10553 verifying acl "default" for ip/port 106.216.115.55:0.
  5. 2023-12-12 05:59:51.473192 96.53% [WARNING] sofia_reg.c:1842 SIP auth challenge (INVITE) on sofia profile 'default' for [10404040404@automation3betav601.astppbilling.org] from ip 106.216.115.55
  6. 2023-12-12 05:59:51.473192 96.53% [DEBUG] switch_core_state_machine.c:600 (sofia/default/90678@automation3betav601.astppbilling.org:5071) State NEW
  7. 2023-12-12 05:59:51.473192 96.53% [DEBUG] sofia.c:2419 detaching session cc368a8c-2cd9-4e10-a5d0-653df1d76675
  8. 2023-12-12 05:59:51.493214 96.53% [DEBUG] switch_rtp.c:5327 Send end packet for [4] ts=138080 dur=960/960/960 seq=33402 lw=138720
  9. 2023-12-12 05:59:51.493214 96.53% [DEBUG] switch_rtp.c:5327 Send end packet for [4] ts=138080 dur=960/960/960 seq=33403 lw=138720
  10. 2023-12-12 05:59:51.493214 96.53% [DEBUG] switch_rtp.c:5327 Send end packet for [4] ts=138080 dur=960/960/960 seq=33404 lw=138720
  11. 2023-12-12 05:59:51.493214 96.53% [DEBUG] switch_rtp.c:5275 Queue digit delay of 40ms
  12. 2023-12-12 05:59:51.733211 96.47% [DEBUG] sofia.c:7493 Channel sofia/default/90678@automation3betav601.astppbilling.org:5071 entering state [ready][200]
  13. 2023-12-12 05:59:51.993240 96.47% [DEBUG] sofia.c:2532 Re-attaching to session cc368a8c-2cd9-4e10-a5d0-653df1d76675
  14. 2023-12-12 05:59:51.993240 96.47% [INFO] sofia.c:10459 sofia/default/90678@automation3betav601.astppbilling.org:5071 receiving invite from 106.216.115.55:54068 version: 1.10.10-release  64bit call-id: NmM4NDUxOTQzYzZiMWUzMmE2OWMzYzliM2ZmZDVmODk.
  15. 2023-12-12 05:59:51.993240 96.47% [DEBUG] sofia.c:10553 verifying acl "default" for ip/port 106.216.115.55:0.
  16. 2023-12-12 05:59:52.013209 96.47% [DEBUG] sofia.c:11674 Setting NAT mode based on via received
  17. 2023-12-12 05:59:52.013209 96.47% [DEBUG] sofia.c:7493 Channel sofia/default/90678@automation3betav601.astppbilling.org:5071 entering state [received][100]
  18. 2023-12-12 05:59:52.013209 96.47% [DEBUG] sofia.c:7503 Remote SDP:
  19. v=0
  20. o=Z 0 0 IN IP4 106.216.115.55
  21. s=Z
  22. c=IN IP4 106.216.115.55
  23. t=0 0
  24. m=audio 8002 RTP/AVP 3 110 8 0 98 101
  25. a=rtpmap:110 speex/8000
  26. a=rtpmap:98 iLBC/8000
  27. a=fmtp:98 mode=20
  28. a=rtpmap:101 telephone-event/8000
  29. a=fmtp:101 0-15
  30.  
  31. 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
  32. 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
  33. 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [speex:110:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
  34. 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [speex:110:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
  35. 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  36. 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_core_media.c:5588 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
  37. 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  38. 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
  39. 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
  40. 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_core_media.c:5588 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
  41. 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [iLBC:98:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
  42. 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [iLBC:98:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
  43. 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_core_media.c:5438 Set telephone-event payload to 101@8000
  44. 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_core_media.c:3734 Set Codec sofia/default/90678@automation3betav601.astppbilling.org:5071 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
  45. 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_core_codec.c:111 sofia/default/90678@automation3betav601.astppbilling.org:5071 Original read codec set to PCMA:8
  46. 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_core_media.c:5798 Set telephone-event payload to 101@8000
  47. 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_core_media.c:5856 sofia/default/90678@automation3betav601.astppbilling.org:5071 Set 2833 dtmf send payload to 101 recv payload to 101
  48. 2023-12-12 05:59:52.013209 96.47% [DEBUG] sofia.c:7927 (sofia/default/90678@automation3betav601.astppbilling.org:5071) State Change CS_NEW -> CS_INIT
  49. 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_core_state_machine.c:581 (sofia/default/90678@automation3betav601.astppbilling.org:5071) Running State Change CS_INIT (Cur 3 Tot 27)
  50. 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_core_state_machine.c:624 (sofia/default/90678@automation3betav601.astppbilling.org:5071) State INIT
  51. 2023-12-12 05:59:52.013209 96.47% [DEBUG] mod_sofia.c:97 sofia/default/90678@automation3betav601.astppbilling.org:5071 SOFIA INIT
  52. 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_core_state_machine.c:40 sofia/default/90678@automation3betav601.astppbilling.org:5071 Standard INIT
  53. 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_core_state_machine.c:48 (sofia/default/90678@automation3betav601.astppbilling.org:5071) State Change CS_INIT -> CS_ROUTING
  54. 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_core_state_machine.c:624 (sofia/default/90678@automation3betav601.astppbilling.org:5071) State INIT going to sleep
  55. 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_core_state_machine.c:581 (sofia/default/90678@automation3betav601.astppbilling.org:5071) Running State Change CS_ROUTING (Cur 3 Tot 27)
  56. 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_channel.c:2399 (sofia/default/90678@automation3betav601.astppbilling.org:5071) Callstate Change DOWN -> RINGING
  57. 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_core_state_machine.c:640 (sofia/default/90678@automation3betav601.astppbilling.org:5071) State ROUTING
  58. 2023-12-12 05:59:52.013209 96.47% [DEBUG] mod_sofia.c:158 sofia/default/90678@automation3betav601.astppbilling.org:5071 SOFIA ROUTING
  59. 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_core_state_machine.c:230 sofia/default/90678@automation3betav601.astppbilling.org:5071 Standard ROUTING
  60. 2023-12-12 05:59:52.013209 96.47% [INFO] mod_dialplan_xml.c:639 Processing 90678 <90678>->10404040404 in context default
  61. 2023-12-12 05:59:52.013209 96.47% [INFO] switch_cpp.cpp:1465 [ASTPP] USING CACHE
  62. 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_SYSTEM]1.0
  63. 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_SYSTEM]1.0
  64. 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
  65. 2023-12-12 05:59:52.033184 96.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Generated XML:
  66. <?xml version="1.0" encoding="UTF-8" standalone="no"?>
  67. <document type="freeswitch/xml">
  68. <section name="dialplan" description="ASTPP Dialplan">
  69. <context name="default">
  70. <extension name="10404040404">
  71. <condition field="destination_number" expression="10404040404">
  72. <action application="playback" data="/usr/local/freeswitch/sounds/en/us/callie/switch_call_traffic_stopped.wav"/>
  73. <action application="set" data="last_bridge_hangup_cause=REQUESTED_CHAN_UNAVAIL"/>
  74. <action application="hangup" data="REQUESTED_CHAN_UNAVAIL"/>
  75. </condition>
  76. </extension>
  77. </context>
  78. </section>
  79. </document>
  80. Dialplan: sofia/default/90678@automation3betav601.astppbilling.org:5071 parsing [default->10404040404] continue=false
  81. Dialplan: sofia/default/90678@automation3betav601.astppbilling.org:5071 Regex (PASS) [10404040404] destination_number(10404040404) =~ /10404040404/ break=on-false
  82. Dialplan: sofia/default/90678@automation3betav601.astppbilling.org:5071 Action playback(/usr/local/freeswitch/sounds/en/us/callie/switch_call_traffic_stopped.wav)
  83. Dialplan: sofia/default/90678@automation3betav601.astppbilling.org:5071 Action set(last_bridge_hangup_cause=REQUESTED_CHAN_UNAVAIL)
  84. Dialplan: sofia/default/90678@automation3betav601.astppbilling.org:5071 Action hangup(REQUESTED_CHAN_UNAVAIL)
  85. 2023-12-12 05:59:52.033184 96.47% [DEBUG] switch_core_state_machine.c:281 (sofia/default/90678@automation3betav601.astppbilling.org:5071) State Change CS_ROUTING -> CS_EXECUTE
  86. 2023-12-12 05:59:52.033184 96.47% [DEBUG] switch_core_state_machine.c:640 (sofia/default/90678@automation3betav601.astppbilling.org:5071) State ROUTING going to sleep
  87. 2023-12-12 05:59:52.033184 96.47% [DEBUG] switch_core_state_machine.c:581 (sofia/default/90678@automation3betav601.astppbilling.org:5071) Running State Change CS_EXECUTE (Cur 3 Tot 27)
  88. 2023-12-12 05:59:52.033184 96.47% [DEBUG] switch_core_state_machine.c:647 (sofia/default/90678@automation3betav601.astppbilling.org:5071) State EXECUTE
  89. 2023-12-12 05:59:52.033184 96.47% [DEBUG] mod_sofia.c:213 sofia/default/90678@automation3betav601.astppbilling.org:5071 SOFIA EXECUTE
  90. 2023-12-12 05:59:52.033184 96.47% [DEBUG] switch_core_state_machine.c:323 sofia/default/90678@automation3betav601.astppbilling.org:5071 Standard EXECUTE
  91. 2023-12-12 05:59:52.033184 96.47% [DEBUG] switch_core_session.c:2791 Application playback Requires media! pre_answering channel sofia/default/90678@automation3betav601.astppbilling.org:5071
  92. 2023-12-12 05:59:52.033184 96.47% [INFO] switch_core_session.c:2793 Sending early media
  93. 2023-12-12 05:59:52.033184 96.47% [DEBUG] switch_core_media.c:8659 AUDIO RTP [sofia/default/90678@automation3betav601.astppbilling.org:5071] 65.109.231.66 port 19890 -> 106.216.115.55 port 8002 codec: 8 ms: 20
  94. 2023-12-12 05:59:52.033184 96.47% [DEBUG] switch_rtp.c:4373 Starting timer [soft] 160 bytes per 20ms
  95. 2023-12-12 05:59:52.033184 96.47% [DEBUG] switch_core_media.c:8972 sofia/default/90678@automation3betav601.astppbilling.org:5071 Set 2833 dtmf send payload to 101
  96. 2023-12-12 05:59:52.033184 96.47% [DEBUG] switch_core_media.c:8979 sofia/default/90678@automation3betav601.astppbilling.org:5071 Set 2833 dtmf receive payload to 101
  97. 2023-12-12 05:59:52.033184 96.47% [DEBUG] switch_core_media.c:9002 sofia/default/90678@automation3betav601.astppbilling.org:5071 Set rtp dtmf delay to 40
  98. 2023-12-12 05:59:52.033184 96.47% [DEBUG] mod_sofia.c:2607 Ring SDP:
  99. v=0
  100. o=FreeSWITCH 1702340902 1702340903 IN IP4 65.109.231.66
  101. s=FreeSWITCH
  102. c=IN IP4 65.109.231.66
  103. t=0 0
  104. m=audio 19890 RTP/AVP 8 101
  105. a=rtpmap:8 PCMA/8000
  106. a=rtpmap:101 telephone-event/8000
  107. a=fmtp:101 0-15
  108. a=ptime:20
  109. a=sendrecv
  110.  
  111. 2023-12-12 05:59:52.033184 96.47% [NOTICE] mod_sofia.c:2610 Pre-Answer sofia/default/90678@automation3betav601.astppbilling.org:5071!
  112. 2023-12-12 05:59:52.033184 96.47% [DEBUG] switch_channel.c:3585 (sofia/default/90678@automation3betav601.astppbilling.org:5071) Callstate Change RINGING -> EARLY
  113. EXECUTE [depth=0] sofia/default/90678@automation3betav601.astppbilling.org:5071 playback(/usr/local/freeswitch/sounds/en/us/callie/switch_call_traffic_stopped.wav)
  114. 2023-12-12 05:59:52.033184 96.47% [WARNING] mod_sndfile.c:281 Error Opening File [/usr/local/freeswitch/sounds/en/us/callie/switch_call_traffic_stopped.wav] [System error : No such file or directory.]
  115. 2023-12-12 05:59:52.033184 96.47% [DEBUG] sofia.c:7493 Channel sofia/default/90678@automation3betav601.astppbilling.org:5071 entering state [early][183]
  116. EXECUTE [depth=0] sofia/default/90678@automation3betav601.astppbilling.org:5071 set(last_bridge_hangup_cause=REQUESTED_CHAN_UNAVAIL)
  117. 2023-12-12 05:59:52.033184 96.47% [DEBUG] mod_dptools.c:1671 SET sofia/default/90678@automation3betav601.astppbilling.org:5071 [last_bridge_hangup_cause]=[REQUESTED_CHAN_UNAVAIL]
  118. EXECUTE [depth=0] sofia/default/90678@automation3betav601.astppbilling.org:5071 hangup(REQUESTED_CHAN_UNAVAIL)
  119. 2023-12-12 05:59:52.033184 96.47% [NOTICE] mod_dptools.c:1374 Hangup sofia/default/90678@automation3betav601.astppbilling.org:5071 [CS_EXECUTE] [REQUESTED_CHAN_UNAVAIL]
  120. 2023-12-12 05:59:52.033184 96.47% [DEBUG] switch_core_session.c:2979 sofia/default/90678@automation3betav601.astppbilling.org:5071 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
  121. 2023-12-12 05:59:52.033184 96.47% [DEBUG] switch_core_state_machine.c:647 (sofia/default/90678@automation3betav601.astppbilling.org:5071) State EXECUTE going to sleep
  122. 2023-12-12 05:59:52.033184 96.47% [DEBUG] switch_core_state_machine.c:581 (sofia/default/90678@automation3betav601.astppbilling.org:5071) Running State Change CS_HANGUP (Cur 3 Tot 27)
  123. 2023-12-12 05:59:52.033184 96.47% [DEBUG] switch_core_state_machine.c:844 (sofia/default/90678@automation3betav601.astppbilling.org:5071) Callstate Change EARLY -> HANGUP
  124. 2023-12-12 05:59:52.033184 96.47% [DEBUG] switch_core_state_machine.c:846 (sofia/default/90678@automation3betav601.astppbilling.org:5071) State HANGUP
  125. 2023-12-12 05:59:52.033184 96.47% [DEBUG] mod_sofia.c:469 Channel sofia/default/90678@automation3betav601.astppbilling.org:5071 hanging up, cause: REQUESTED_CHAN_UNAVAIL
  126. 2023-12-12 05:59:52.033184 96.47% [DEBUG] mod_sofia.c:614 Responding to INVITE with: 503
  127. 2023-12-12 05:59:52.033184 96.47% [DEBUG] switch_core_state_machine.c:59 sofia/default/90678@automation3betav601.astppbilling.org:5071 Standard HANGUP, cause: REQUESTED_CHAN_UNAVAIL
  128. 2023-12-12 05:59:52.033184 96.47% [DEBUG] switch_core_state_machine.c:846 (sofia/default/90678@automation3betav601.astppbilling.org:5071) State HANGUP going to sleep
  129. 2023-12-12 05:59:52.033184 96.47% [DEBUG] switch_core_state_machine.c:616 (sofia/default/90678@automation3betav601.astppbilling.org:5071) State Change CS_HANGUP -> CS_REPORTING
  130. 2023-12-12 05:59:52.033184 96.47% [DEBUG] switch_core_state_machine.c:581 (sofia/default/90678@automation3betav601.astppbilling.org:5071) Running State Change CS_REPORTING (Cur 3 Tot 27)
  131. 2023-12-12 05:59:52.033184 96.47% [DEBUG] switch_core_state_machine.c:932 (sofia/default/90678@automation3betav601.astppbilling.org:5071) State REPORTING
  132. 2023-12-12 05:59:52.033184 96.47% [INFO] mod_json_cdr.c:272 Process [cc368a8c-2cd9-4e10-a5d0-653df1d76675.cdr.json]
  133. 2023-12-12 05:59:52.053190 96.47% [DEBUG] switch_core_state_machine.c:168 sofia/default/90678@automation3betav601.astppbilling.org:5071 Standard REPORTING, cause: REQUESTED_CHAN_UNAVAIL
  134. 2023-12-12 05:59:52.053190 96.47% [DEBUG] switch_core_state_machine.c:932 (sofia/default/90678@automation3betav601.astppbilling.org:5071) State REPORTING going to sleep
  135. 2023-12-12 05:59:52.053190 96.47% [DEBUG] switch_core_state_machine.c:607 (sofia/default/90678@automation3betav601.astppbilling.org:5071) State Change CS_REPORTING -> CS_DESTROY
  136. 2023-12-12 05:59:52.053190 96.47% [DEBUG] switch_core_session.c:1744 Session 27 (sofia/default/90678@automation3betav601.astppbilling.org:5071) Locked, Waiting on external entities
  137. 2023-12-12 05:59:52.053190 96.47% [NOTICE] switch_core_session.c:1762 Session 27 (sofia/default/90678@automation3betav601.astppbilling.org:5071) Ended
  138. 2023-12-12 05:59:52.053190 96.47% [NOTICE] switch_core_session.c:1766 Close Channel sofia/default/90678@automation3betav601.astppbilling.org:5071 [CS_DESTROY]
  139. 2023-12-12 05:59:52.053190 96.47% [DEBUG] switch_core_state_machine.c:735 (sofia/default/90678@automation3betav601.astppbilling.org:5071) Running State Change CS_DESTROY (Cur 2 Tot 27)
  140. 2023-12-12 05:59:52.053190 96.47% [DEBUG] switch_core_state_machine.c:745 (sofia/default/90678@automation3betav601.astppbilling.org:5071) State DESTROY
  141. 2023-12-12 05:59:52.053190 96.47% [DEBUG] mod_sofia.c:380 sofia/default/90678@automation3betav601.astppbilling.org:5071 SOFIA DESTROY
  142. 2023-12-12 05:59:52.053190 96.47% [DEBUG] switch_core_state_machine.c:175 sofia/default/90678@automation3betav601.astppbilling.org:5071 Standard DESTROY
  143. 2023-12-12 05:59:52.053190 96.47% [DEBUG] switch_core_state_machine.c:745 (sofia/default/90678@automation3betav601.astppbilling.org:5071) State DESTROY going to sleep
  144. 2023-12-12 05:59:56.153245 96.30% [DEBUG] switch_channel.c:2179 (sofia/default/90678@automation3betav601.astppbilling.org:5071) Callstate Change HELD -> UNHELD
  145. 2023-12-12 05:59:56.153245 96.30% [NOTICE] sofia.c:1065 Hangup sofia/default/90678@automation3betav601.astppbilling.org:5071 [CS_EXECUTE] [NORMAL_CLEARING]
  146. 2023-12-12 05:59:56.153245 96.30% [DEBUG] switch_ivr_bridge.c:911 BRIDGE THREAD DONE [sofia/default/90678@automation3betav601.astppbilling.org:5071]
  147. 2023-12-12 05:59:56.153245 96.30% [NOTICE] switch_ivr_bridge.c:926 Hangup sofia/default/1030404040404 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
  148. 2023-12-12 05:59:56.153245 96.30% [DEBUG] switch_ivr_bridge.c:1890 sofia/default/1030404040404 skip receive message [UNBRIDGE] (channel is hungup already)
  149. 2023-12-12 05:59:56.153245 96.30% [DEBUG] switch_ivr_bridge.c:1893 sofia/default/90678@automation3betav601.astppbilling.org:5071 skip receive message [UNBRIDGE] (channel is hungup already)
  150. 2023-12-12 05:59:56.153245 96.30% [DEBUG] switch_core_session.c:2979 sofia/default/90678@automation3betav601.astppbilling.org:5071 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
  151. 2023-12-12 05:59:56.153245 96.30% [DEBUG] switch_core_state_machine.c:647 (sofia/default/90678@automation3betav601.astppbilling.org:5071) State EXECUTE going to sleep
  152. 2023-12-12 05:59:56.153245 96.30% [DEBUG] switch_core_state_machine.c:581 (sofia/default/90678@automation3betav601.astppbilling.org:5071) Running State Change CS_HANGUP (Cur 2 Tot 27)
  153. 2023-12-12 05:59:56.153245 96.30% [DEBUG] switch_ivr_async.c:1597 Stop recording file /usr/local/freeswitch/recordings/3e79df31-8f30-4a03-a8a7-e0c7e7831ccf.wav
  154. 2023-12-12 05:59:56.153245 96.30% [DEBUG] switch_ivr_async.c:1678 Channel is hung up
  155. 2023-12-12 05:59:56.153245 96.30% [DEBUG] switch_core_media_bug.c:1326 Removing BUG from sofia/default/90678@automation3betav601.astppbilling.org:5071
  156. 2023-12-12 05:59:56.153245 96.30% [DEBUG] switch_core_state_machine.c:844 (sofia/default/90678@automation3betav601.astppbilling.org:5071) Callstate Change UNHELD -> HANGUP
  157. 2023-12-12 05:59:56.153245 96.30% [DEBUG] switch_core_state_machine.c:846 (sofia/default/90678@automation3betav601.astppbilling.org:5071) State HANGUP
  158. 2023-12-12 05:59:56.153245 96.30% [DEBUG] mod_sofia.c:469 Channel sofia/default/90678@automation3betav601.astppbilling.org:5071 hanging up, cause: NORMAL_CLEARING
  159. 2023-12-12 05:59:56.153245 96.30% [DEBUG] switch_core_state_machine.c:59 sofia/default/90678@automation3betav601.astppbilling.org:5071 Standard HANGUP, cause: NORMAL_CLEARING
  160. 2023-12-12 05:59:56.153245 96.30% [DEBUG] switch_core_state_machine.c:846 (sofia/default/90678@automation3betav601.astppbilling.org:5071) State HANGUP going to sleep
  161. 2023-12-12 05:59:56.153245 96.30% [DEBUG] switch_core_state_machine.c:616 (sofia/default/90678@automation3betav601.astppbilling.org:5071) State Change CS_HANGUP -> CS_REPORTING
  162. 2023-12-12 05:59:56.153245 96.30% [DEBUG] switch_core_state_machine.c:581 (sofia/default/90678@automation3betav601.astppbilling.org:5071) Running State Change CS_REPORTING (Cur 2 Tot 27)
  163. 2023-12-12 05:59:56.153245 96.30% [DEBUG] switch_core_state_machine.c:932 (sofia/default/90678@automation3betav601.astppbilling.org:5071) State REPORTING
  164. 2023-12-12 05:59:56.153245 96.30% [INFO] mod_json_cdr.c:272 Process [3e79df31-8f30-4a03-a8a7-e0c7e7831ccf.cdr.json]
  165. 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_ivr_play_say.c:2010 done playing file local_stream://moh
  166. 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_session.c:2979 sofia/default/1030404040404 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
  167. 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_ivr_bridge.c:567 sofia/default/1030404040404 skip receive message [BRIDGE] (channel is hungup already)
  168. 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_ivr.c:679 sofia/default/1030404040404 skip receive message [AUDIO_SYNC] (channel is hungup already)
  169. 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_ivr_bridge.c:825 sofia/default/1030404040404 ending bridge by request from read function
  170. 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_ivr_bridge.c:911 BRIDGE THREAD DONE [sofia/default/1030404040404]
  171. 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_state_machine.c:650 (sofia/default/1030404040404) State EXCHANGE_MEDIA going to sleep
  172. 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1030404040404) Running State Change CS_HANGUP (Cur 2 Tot 27)
  173. 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_ivr_async.c:1597 Stop recording file /usr/local/freeswitch/recordings/3e79df31-8f30-4a03-a8a7-e0c7e7831ccf.wav
  174. 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_ivr_async.c:1678 Channel is hung up
  175. 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_media_bug.c:1326 Removing BUG from sofia/default/1030404040404
  176. 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_state_machine.c:844 (sofia/default/1030404040404) Callstate Change ACTIVE -> HANGUP
  177. 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_state_machine.c:846 (sofia/default/1030404040404) State HANGUP
  178. 2023-12-12 05:59:56.173187 96.30% [DEBUG] mod_sofia.c:463 sofia/default/1030404040404 Overriding SIP cause 480 with 200 from the other leg
  179. 2023-12-12 05:59:56.173187 96.30% [DEBUG] mod_sofia.c:469 Channel sofia/default/1030404040404 hanging up, cause: NORMAL_CLEARING
  180. 2023-12-12 05:59:56.173187 96.30% [DEBUG] mod_sofia.c:523 Sending BYE to sofia/default/1030404040404
  181. 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_state_machine.c:59 sofia/default/1030404040404 Standard HANGUP, cause: NORMAL_CLEARING
  182. 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_state_machine.c:846 (sofia/default/1030404040404) State HANGUP going to sleep
  183. 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_state_machine.c:616 (sofia/default/1030404040404) State Change CS_HANGUP -> CS_REPORTING
  184. 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_state_machine.c:581 (sofia/default/1030404040404) Running State Change CS_REPORTING (Cur 2 Tot 27)
  185. 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_state_machine.c:932 (sofia/default/1030404040404) State REPORTING
  186. 2023-12-12 05:59:56.173187 96.30% [INFO] mod_json_cdr.c:272 Process [7ea93000-83a8-4df1-9237-7d942b314001.cdr.json]
  187. 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_state_machine.c:168 sofia/default/1030404040404 Standard REPORTING, cause: NORMAL_CLEARING
  188. 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_state_machine.c:932 (sofia/default/1030404040404) State REPORTING going to sleep
  189. 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_state_machine.c:607 (sofia/default/1030404040404) State Change CS_REPORTING -> CS_DESTROY
  190. 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_session.c:1744 Session 26 (sofia/default/1030404040404) Locked, Waiting on external entities
  191. 2023-12-12 05:59:56.173187 96.30% [NOTICE] switch_core_session.c:1762 Session 26 (sofia/default/1030404040404) Ended
  192. 2023-12-12 05:59:56.173187 96.30% [NOTICE] switch_core_session.c:1766 Close Channel sofia/default/1030404040404 [CS_DESTROY]
  193. 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_state_machine.c:735 (sofia/default/1030404040404) Running State Change CS_DESTROY (Cur 1 Tot 27)
  194. 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_state_machine.c:745 (sofia/default/1030404040404) State DESTROY
  195. 2023-12-12 05:59:56.173187 96.30% [DEBUG] mod_sofia.c:380 sofia/default/1030404040404 SOFIA DESTROY
  196. 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_state_machine.c:175 sofia/default/1030404040404 Standard DESTROY
  197. 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_state_machine.c:745 (sofia/default/1030404040404) State DESTROY going to sleep
  198. 2023-12-12 05:59:56.193219 96.30% [DEBUG] switch_core_state_machine.c:168 sofia/default/90678@automation3betav601.astppbilling.org:5071 Standard REPORTING, cause: NORMAL_CLEARING
  199. 2023-12-12 05:59:56.193219 96.30% [DEBUG] switch_core_state_machine.c:932 (sofia/default/90678@automation3betav601.astppbilling.org:5071) State REPORTING going to sleep
  200. 2023-12-12 05:59:56.193219 96.30% [DEBUG] switch_core_state_machine.c:607 (sofia/default/90678@automation3betav601.astppbilling.org:5071) State Change CS_REPORTING -> CS_DESTROY
  201. 2023-12-12 05:59:56.193219 96.30% [DEBUG] switch_core_session.c:1744 Session 25 (sofia/default/90678@automation3betav601.astppbilling.org:5071) Locked, Waiting on external entities
  202. 2023-12-12 05:59:56.193219 96.30% [NOTICE] switch_core_session.c:1762 Session 25 (sofia/default/90678@automation3betav601.astppbilling.org:5071) Ended
  203. 2023-12-12 05:59:56.193219 96.30% [NOTICE] switch_core_session.c:1766 Close Channel sofia/default/90678@automation3betav601.astppbilling.org:5071 [CS_DESTROY]
  204. 2023-12-12 05:59:56.193219 96.30% [DEBUG] switch_core_state_machine.c:735 (sofia/default/90678@automation3betav601.astppbilling.org:5071) Running State Change CS_DESTROY (Cur 0 Tot 27)
  205. 2023-12-12 05:59:56.193219 96.30% [DEBUG] switch_core_state_machine.c:745 (sofia/default/90678@automation3betav601.astppbilling.org:5071) State DESTROY
  206. 2023-12-12 05:59:56.193219 96.30% [DEBUG] mod_sofia.c:380 sofia/default/90678@automation3betav601.astppbilling.org:5071 SOFIA DESTROY
  207. 2023-12-12 05:59:56.193219 96.30% [DEBUG] switch_core_state_machine.c:175 sofia/default/90678@automation3betav601.astppbilling.org:5071 Standard DESTROY
  208. 2023-12-12 05:59:56.193219 96.30% [DEBUG] switch_core_state_machine.c:745 (sofia/default/90678@automation3betav601.astppbilling.org:5071) State DESTROY going to sleep
  209. 2023-12-12 05:59:56.353219 96.30% [DEBUG] switch_scheduler.c:147 Deleting task 10 switch_ivr_schedule_hangup (7ea93000-83a8-4df1-9237-7d942b314001)