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] 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) 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. 2023-12-12 05:59:51.473192 96.53% [DEBUG] sofia.c:10553 verifying acl "default" for ip/port 106.216.115.55:0. 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 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 2023-12-12 05:59:51.473192 96.53% [DEBUG] sofia.c:2419 detaching session cc368a8c-2cd9-4e10-a5d0-653df1d76675 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 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 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 2023-12-12 05:59:51.493214 96.53% [DEBUG] switch_rtp.c:5275 Queue digit delay of 40ms 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] 2023-12-12 05:59:51.993240 96.47% [DEBUG] sofia.c:2532 Re-attaching to session cc368a8c-2cd9-4e10-a5d0-653df1d76675 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. 2023-12-12 05:59:51.993240 96.47% [DEBUG] sofia.c:10553 verifying acl "default" for ip/port 106.216.115.55:0. 2023-12-12 05:59:52.013209 96.47% [DEBUG] sofia.c:11674 Setting NAT mode based on via received 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] 2023-12-12 05:59:52.013209 96.47% [DEBUG] sofia.c:7503 Remote SDP: v=0 o=Z 0 0 IN IP4 106.216.115.55 s=Z c=IN IP4 106.216.115.55 t=0 0 m=audio 8002 RTP/AVP 3 110 8 0 98 101 a=rtpmap:110 speex/8000 a=rtpmap:98 iLBC/8000 a=fmtp:98 mode=20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 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] 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] 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] 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] 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] 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 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] 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] 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] 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 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] 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] 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_core_media.c:5438 Set telephone-event payload to 101@8000 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 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 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_core_media.c:5798 Set telephone-event payload to 101@8000 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 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 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) 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 2023-12-12 05:59:52.013209 96.47% [DEBUG] mod_sofia.c:97 sofia/default/90678@automation3betav601.astppbilling.org:5071 SOFIA INIT 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 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 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 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) 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 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 2023-12-12 05:59:52.013209 96.47% [DEBUG] mod_sofia.c:158 sofia/default/90678@automation3betav601.astppbilling.org:5071 SOFIA ROUTING 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 2023-12-12 05:59:52.013209 96.47% [INFO] mod_dialplan_xml.c:639 Processing 90678 <90678>->10404040404 in context default 2023-12-12 05:59:52.013209 96.47% [INFO] switch_cpp.cpp:1465 [ASTPP] USING CACHE 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_SYSTEM]1.0 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_SYSTEM]1.0 2023-12-12 05:59:52.013209 96.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons 2023-12-12 05:59:52.033184 96.47% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Generated XML:
Dialplan: sofia/default/90678@automation3betav601.astppbilling.org:5071 parsing [default->10404040404] continue=false Dialplan: sofia/default/90678@automation3betav601.astppbilling.org:5071 Regex (PASS) [10404040404] destination_number(10404040404) =~ /10404040404/ break=on-false Dialplan: sofia/default/90678@automation3betav601.astppbilling.org:5071 Action playback(/usr/local/freeswitch/sounds/en/us/callie/switch_call_traffic_stopped.wav) Dialplan: sofia/default/90678@automation3betav601.astppbilling.org:5071 Action set(last_bridge_hangup_cause=REQUESTED_CHAN_UNAVAIL) Dialplan: sofia/default/90678@automation3betav601.astppbilling.org:5071 Action hangup(REQUESTED_CHAN_UNAVAIL) 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 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 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) 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 2023-12-12 05:59:52.033184 96.47% [DEBUG] mod_sofia.c:213 sofia/default/90678@automation3betav601.astppbilling.org:5071 SOFIA EXECUTE 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 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 2023-12-12 05:59:52.033184 96.47% [INFO] switch_core_session.c:2793 Sending early media 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 2023-12-12 05:59:52.033184 96.47% [DEBUG] switch_rtp.c:4373 Starting timer [soft] 160 bytes per 20ms 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 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 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 2023-12-12 05:59:52.033184 96.47% [DEBUG] mod_sofia.c:2607 Ring SDP: v=0 o=FreeSWITCH 1702340902 1702340903 IN IP4 65.109.231.66 s=FreeSWITCH c=IN IP4 65.109.231.66 t=0 0 m=audio 19890 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv 2023-12-12 05:59:52.033184 96.47% [NOTICE] mod_sofia.c:2610 Pre-Answer sofia/default/90678@automation3betav601.astppbilling.org:5071! 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 EXECUTE [depth=0] sofia/default/90678@automation3betav601.astppbilling.org:5071 playback(/usr/local/freeswitch/sounds/en/us/callie/switch_call_traffic_stopped.wav) 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.] 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] EXECUTE [depth=0] sofia/default/90678@automation3betav601.astppbilling.org:5071 set(last_bridge_hangup_cause=REQUESTED_CHAN_UNAVAIL) 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] EXECUTE [depth=0] sofia/default/90678@automation3betav601.astppbilling.org:5071 hangup(REQUESTED_CHAN_UNAVAIL) 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] 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) 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 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) 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 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 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 2023-12-12 05:59:52.033184 96.47% [DEBUG] mod_sofia.c:614 Responding to INVITE with: 503 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 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 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 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) 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 2023-12-12 05:59:52.033184 96.47% [INFO] mod_json_cdr.c:272 Process [cc368a8c-2cd9-4e10-a5d0-653df1d76675.cdr.json] 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 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 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 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 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 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] 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) 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 2023-12-12 05:59:52.053190 96.47% [DEBUG] mod_sofia.c:380 sofia/default/90678@automation3betav601.astppbilling.org:5071 SOFIA DESTROY 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 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 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 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] 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] 2023-12-12 05:59:56.153245 96.30% [NOTICE] switch_ivr_bridge.c:926 Hangup sofia/default/1030404040404 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] 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) 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) 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) 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 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) 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 2023-12-12 05:59:56.153245 96.30% [DEBUG] switch_ivr_async.c:1678 Channel is hung up 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 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 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 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 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 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 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 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) 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 2023-12-12 05:59:56.153245 96.30% [INFO] mod_json_cdr.c:272 Process [3e79df31-8f30-4a03-a8a7-e0c7e7831ccf.cdr.json] 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_ivr_play_say.c:2010 done playing file local_stream://moh 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) 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) 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) 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 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_ivr_bridge.c:911 BRIDGE THREAD DONE [sofia/default/1030404040404] 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 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) 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 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_ivr_async.c:1678 Channel is hung up 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_media_bug.c:1326 Removing BUG from sofia/default/1030404040404 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_state_machine.c:844 (sofia/default/1030404040404) Callstate Change ACTIVE -> HANGUP 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_state_machine.c:846 (sofia/default/1030404040404) State HANGUP 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 2023-12-12 05:59:56.173187 96.30% [DEBUG] mod_sofia.c:469 Channel sofia/default/1030404040404 hanging up, cause: NORMAL_CLEARING 2023-12-12 05:59:56.173187 96.30% [DEBUG] mod_sofia.c:523 Sending BYE to sofia/default/1030404040404 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_state_machine.c:59 sofia/default/1030404040404 Standard HANGUP, cause: NORMAL_CLEARING 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_state_machine.c:846 (sofia/default/1030404040404) State HANGUP going to sleep 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 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) 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_state_machine.c:932 (sofia/default/1030404040404) State REPORTING 2023-12-12 05:59:56.173187 96.30% [INFO] mod_json_cdr.c:272 Process [7ea93000-83a8-4df1-9237-7d942b314001.cdr.json] 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_state_machine.c:168 sofia/default/1030404040404 Standard REPORTING, cause: NORMAL_CLEARING 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_state_machine.c:932 (sofia/default/1030404040404) State REPORTING going to sleep 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 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 2023-12-12 05:59:56.173187 96.30% [NOTICE] switch_core_session.c:1762 Session 26 (sofia/default/1030404040404) Ended 2023-12-12 05:59:56.173187 96.30% [NOTICE] switch_core_session.c:1766 Close Channel sofia/default/1030404040404 [CS_DESTROY] 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) 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_state_machine.c:745 (sofia/default/1030404040404) State DESTROY 2023-12-12 05:59:56.173187 96.30% [DEBUG] mod_sofia.c:380 sofia/default/1030404040404 SOFIA DESTROY 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_state_machine.c:175 sofia/default/1030404040404 Standard DESTROY 2023-12-12 05:59:56.173187 96.30% [DEBUG] switch_core_state_machine.c:745 (sofia/default/1030404040404) State DESTROY going to sleep 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 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 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 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 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 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] 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) 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 2023-12-12 05:59:56.193219 96.30% [DEBUG] mod_sofia.c:380 sofia/default/90678@automation3betav601.astppbilling.org:5071 SOFIA DESTROY 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 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 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)