+OK log level [7]
freeswitch@ip-172-31-42-21>
freeswitch@ip-172-31-42-21>
2024-02-23 11:23:51.306483 98.67% [NOTICE] switch_channel.c:1142 New Channel sofia/default/9669963218@pk1betav602.astppbilling.org:5078 [ccb94ef2-5384-438d-946a-e4e9ef78959d]
2024-02-23 11:23:51.306483 98.67% [DEBUG] switch_core_state_machine.c:581 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) Running State Change CS_NEW (Cur 1 Tot 9259)
2024-02-23 11:23:51.306483 98.67% [INFO] sofia.c:10459 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 receiving invite from 223.228.239.129:32416 version: 1.10.10-release 64bit call-id: OWE2OGFiMzMwZGM2YmZiODVhNWQ0M2IzMGYwOTIwOGY.
2024-02-23 11:23:51.306483 98.67% [DEBUG] sofia.c:10553 verifying acl "default" for ip/port 223.228.239.129:0.
2024-02-23 11:23:51.306483 98.67% [DEBUG] sofia.c:2419 detaching session ccb94ef2-5384-438d-946a-e4e9ef78959d
2024-02-23 11:23:51.306483 98.67% [WARNING] sofia_reg.c:1842 SIP auth challenge (INVITE) on sofia profile 'default' for [*101@pk1betav602.astppbilling.org] from ip 223.228.239.129
2024-02-23 11:23:51.306483 98.67% [DEBUG] switch_core_state_machine.c:600 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State NEW
2024-02-23 11:23:51.726491 98.70% [DEBUG] sofia.c:2532 Re-attaching to session ccb94ef2-5384-438d-946a-e4e9ef78959d
2024-02-23 11:23:51.726491 98.70% [INFO] sofia.c:10459 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 receiving invite from 223.228.239.129:32416 version: 1.10.10-release 64bit call-id: OWE2OGFiMzMwZGM2YmZiODVhNWQ0M2IzMGYwOTIwOGY.
2024-02-23 11:23:51.726491 98.70% [DEBUG] sofia.c:10553 verifying acl "default" for ip/port 223.228.239.129:0.
2024-02-23 11:23:51.746466 98.70% [DEBUG] sofia.c:11674 Setting NAT mode based on via received
2024-02-23 11:23:51.746466 98.70% [DEBUG] sofia.c:7493 Channel sofia/default/9669963218@pk1betav602.astppbilling.org:5078 entering state [received][100]
2024-02-23 11:23:51.746466 98.70% [DEBUG] sofia.c:7503 Remote SDP:
v=0
o=Z 0 0 IN IP4 223.228.239.129
s=Z
c=IN IP4 223.228.239.129
t=0 0
m=audio 8000 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
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [speex:110:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [speex:110:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_core_media.c:5588 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_core_media.c:5588 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [iLBC:98:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [iLBC:98:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_core_media.c:5438 Set telephone-event payload to 101@8000
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_core_media.c:3734 Set Codec sofia/default/9669963218@pk1betav602.astppbilling.org:5078 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_core_codec.c:111 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 Original read codec set to PCMA:8
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_core_media.c:5798 Set telephone-event payload to 101@8000
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_core_media.c:5856 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 Set 2833 dtmf send payload to 101 recv payload to 101
2024-02-23 11:23:51.746466 98.70% [DEBUG] sofia.c:7927 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State Change CS_NEW -> CS_INIT
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_core_state_machine.c:581 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) Running State Change CS_INIT (Cur 1 Tot 9259)
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_core_state_machine.c:624 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State INIT
2024-02-23 11:23:51.746466 98.70% [DEBUG] mod_sofia.c:97 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 SOFIA INIT
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_core_state_machine.c:40 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 Standard INIT
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_core_state_machine.c:48 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State Change CS_INIT -> CS_ROUTING
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_core_state_machine.c:624 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State INIT going to sleep
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_core_state_machine.c:581 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) Running State Change CS_ROUTING (Cur 1 Tot 9259)
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_channel.c:2399 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) Callstate Change DOWN -> RINGING
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_core_state_machine.c:640 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State ROUTING
2024-02-23 11:23:51.746466 98.70% [DEBUG] mod_sofia.c:158 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 SOFIA ROUTING
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_core_state_machine.c:230 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 Standard ROUTING
2024-02-23 11:23:51.746466 98.70% [INFO] mod_dialplan_xml.c:639 Processing 9669963218 <9669963218>->*101 in context default
2024-02-23 11:23:51.746466 98.70% [INFO] switch_cpp.cpp:1465 [ASTPP] USING CACHE
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_SYSTEM]1.0
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_SYSTEM]1.0
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
2024-02-23 11:23:51.746466 98.70% [INFO] switch_cpp.cpp:1465 [ASTPP] [feature_code_call_transfer] Blind Call Flag: 0
2024-02-23 11:23:51.746466 98.70% [INFO] switch_cpp.cpp:1465 [ASTPP] [feature_code_call_transfer] Hunt Destination Number: *101
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CHECK_FEATURE_CODE] Query :SELECT id,feature_action,feature_code from feature_code where feature_action = 'call_transfer_attended' limit 1
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CHECK_FEATURE_CODE] Query :SELECT id,feature_action,feature_code from feature_code where feature_action = 'call_transfer' limit 1
2024-02-23 11:23:51.746466 98.70% [INFO] switch_cpp.cpp:1465 [ASTPP] [feature_code_call_transfer] Feature Code Transfer Blind Value :*2
2024-02-23 11:23:51.746466 98.70% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] Dialed number : *101
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_ACCESS_NUMBER]1.0
2024-02-23 11:23:51.746466 98.70% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] VOICEMAIL :
2024-02-23 11:23:51.746466 98.70% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Generated XML:
Dialplan: sofia/default/9669963218@pk1betav602.astppbilling.org:5078 parsing [default->\*101] continue=false
Dialplan: sofia/default/9669963218@pk1betav602.astppbilling.org:5078 Regex (PASS) [\*101] destination_number(*101) =~ /\*101/ break=on-false
Dialplan: sofia/default/9669963218@pk1betav602.astppbilling.org:5078 Action answer()
Dialplan: sofia/default/9669963218@pk1betav602.astppbilling.org:5078 Action voicemail(check default pk1betav602.astppbilling.org 9669963218)
2024-02-23 11:23:51.766467 98.70% [DEBUG] switch_core_state_machine.c:281 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State Change CS_ROUTING -> CS_EXECUTE
2024-02-23 11:23:51.766467 98.70% [DEBUG] switch_core_state_machine.c:640 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State ROUTING going to sleep
2024-02-23 11:23:51.766467 98.70% [DEBUG] switch_core_state_machine.c:581 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) Running State Change CS_EXECUTE (Cur 1 Tot 9259)
2024-02-23 11:23:51.766467 98.70% [DEBUG] switch_core_state_machine.c:647 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State EXECUTE
2024-02-23 11:23:51.766467 98.70% [DEBUG] mod_sofia.c:213 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 SOFIA EXECUTE
2024-02-23 11:23:51.766467 98.70% [DEBUG] switch_core_state_machine.c:323 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 Standard EXECUTE
EXECUTE [depth=0] sofia/default/9669963218@pk1betav602.astppbilling.org:5078 answer()
2024-02-23 11:23:51.766467 98.70% [DEBUG] switch_core_media.c:8659 AUDIO RTP [sofia/default/9669963218@pk1betav602.astppbilling.org:5078] 172.31.42.21 port 27426 -> 223.228.239.129 port 8000 codec: 8 ms: 20
2024-02-23 11:23:51.766467 98.70% [DEBUG] switch_rtp.c:4373 Starting timer [soft] 160 bytes per 20ms
2024-02-23 11:23:51.766467 98.70% [DEBUG] switch_core_media.c:8972 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 Set 2833 dtmf send payload to 101
2024-02-23 11:23:51.766467 98.70% [DEBUG] switch_core_media.c:8979 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 Set 2833 dtmf receive payload to 101
2024-02-23 11:23:51.766467 98.70% [DEBUG] switch_core_media.c:9002 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 Set rtp dtmf delay to 40
2024-02-23 11:23:51.766467 98.70% [DEBUG] mod_sofia.c:914 Local SDP sofia/default/9669963218@pk1betav602.astppbilling.org:5078:
v=0
o=FreeSWITCH 1708660005 1708660006 IN IP4 35.154.93.145
s=FreeSWITCH
c=IN IP4 35.154.93.145
t=0 0
m=audio 27426 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
2024-02-23 11:23:51.766467 98.70% [DEBUG] sofia.c:7493 Channel sofia/default/9669963218@pk1betav602.astppbilling.org:5078 entering state [completed][200]
2024-02-23 11:23:51.766467 98.70% [NOTICE] mod_dptools.c:1406 Channel [sofia/default/9669963218@pk1betav602.astppbilling.org:5078] has been answered
2024-02-23 11:23:51.766467 98.70% [DEBUG] switch_channel.c:3912 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) Callstate Change RINGING -> ACTIVE
EXECUTE [depth=0] sofia/default/9669963218@pk1betav602.astppbilling.org:5078 voicemail(check default pk1betav602.astppbilling.org 9669963218)
2024-02-23 11:23:51.766467 98.70% [DEBUG] switch_ivr_play_say.c:70 No language specified - Using [en]
2024-02-23 11:23:52.006465 98.70% [DEBUG] switch_ivr_play_say.c:70 No language specified - Using [en]
2024-02-23 11:23:52.006465 98.70% [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-enter_pass.wav] (en:en)
2024-02-23 11:23:52.006465 98.70% [DEBUG] switch_ivr_play_say.c:262 Setting playback volume to 0
2024-02-23 11:23:52.006465 98.70% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:23:52.046465 98.70% [DEBUG] switch_rtp.c:7503 Correct audio ip/port confirmed.
2024-02-23 11:23:52.066466 98.70% [DEBUG] sofia.c:7493 Channel sofia/default/9669963218@pk1betav602.astppbilling.org:5078 entering state [ready][200]
2024-02-23 11:23:53.946486 98.43% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-enter_pass.wav
2024-02-23 11:23:54.046487 98.43% [DEBUG] switch_ivr_play_say.c:250 Handle say:[#] (en:en)
2024-02-23 11:23:54.046487 98.43% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:23:54.706492 98.40% [DEBUG] switch_ivr_play_say.c:2010 done playing file file_string://ascii/35.wav
2024-02-23 11:24:04.946468 95.57% [DEBUG] switch_ivr_play_say.c:70 No language specified - Using [en]
2024-02-23 11:24:04.946468 95.57% [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-enter_pass.wav] (en:en)
2024-02-23 11:24:04.946468 95.57% [DEBUG] switch_ivr_play_say.c:262 Setting playback volume to 0
2024-02-23 11:24:04.946468 95.57% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:24:06.886491 95.17% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-enter_pass.wav
2024-02-23 11:24:06.986491 95.17% [DEBUG] switch_ivr_play_say.c:250 Handle say:[#] (en:en)
2024-02-23 11:24:06.986491 95.17% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:24:07.646474 95.07% [DEBUG] switch_ivr_play_say.c:2010 done playing file file_string://ascii/35.wav
2024-02-23 11:24:12.086485 95.00% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 7:960
2024-02-23 11:24:12.086485 95.00% [INFO] switch_channel.c:528 RECV DTMF 7:960
2024-02-23 11:24:12.706485 94.93% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 9:960
2024-02-23 11:24:12.706485 94.93% [INFO] switch_channel.c:528 RECV DTMF 9:960
2024-02-23 11:24:13.826465 94.87% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 5:960
2024-02-23 11:24:13.826465 94.87% [INFO] switch_channel.c:528 RECV DTMF 5:960
2024-02-23 11:24:14.306484 94.87% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 9:960
2024-02-23 11:24:14.306484 94.87% [INFO] switch_channel.c:528 RECV DTMF 9:960
2024-02-23 11:24:14.526483 94.83% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF 0:960
2024-02-23 11:24:14.526483 94.83% [INFO] switch_channel.c:528 RECV DTMF 0:960
2024-02-23 11:24:15.246485 94.83% [DEBUG] switch_rtp.c:7748 RTP RECV DTMF #:960
2024-02-23 11:24:15.246485 94.83% [INFO] switch_channel.c:528 RECV DTMF #:960
2024-02-23 11:24:15.366463 94.83% [DEBUG] switch_ivr_play_say.c:70 No language specified - Using [en]
2024-02-23 11:24:15.366463 94.83% [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-you_have.wav] (en:en)
2024-02-23 11:24:15.366463 94.83% [DEBUG] switch_ivr_play_say.c:262 Setting playback volume to 0
2024-02-23 11:24:15.366463 94.83% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:24:15.926485 94.77% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-you_have.wav
2024-02-23 11:24:16.026553 94.77% [DEBUG] switch_ivr_play_say.c:250 Handle say:[1] (en:en)
2024-02-23 11:24:16.026553 94.77% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:24:16.726463 94.73% [DEBUG] switch_ivr_play_say.c:2010 done playing file file_string://digits/1.wav
2024-02-23 11:24:16.826490 94.73% [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-urgent-new.wav] (en:en)
2024-02-23 11:24:16.826490 94.73% [DEBUG] switch_ivr_play_say.c:262 Setting playback volume to 0
2024-02-23 11:24:16.826490 94.73% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:24:17.606485 94.60% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-urgent-new.wav
2024-02-23 11:24:17.726487 94.60% [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-message.wav] (en:en)
2024-02-23 11:24:17.726487 94.60% [DEBUG] switch_ivr_play_say.c:262 Setting playback volume to 0
2024-02-23 11:24:17.726487 94.60% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:24:18.306488 94.60% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-message.wav
2024-02-23 11:24:18.526493 94.37% [DEBUG] mod_voicemail.c:1604 Sending display update [1119705264|1119705264] to sofia/default/9669963218@pk1betav602.astppbilling.org:5078
2024-02-23 11:24:18.526493 94.37% [DEBUG] switch_ivr_play_say.c:70 No language specified - Using [en]
2024-02-23 11:24:18.526493 94.37% [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-new.wav] (en:en)
2024-02-23 11:24:18.526493 94.37% [DEBUG] switch_ivr_play_say.c:262 Setting playback volume to 0
2024-02-23 11:24:18.526493 94.37% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:24:18.866491 94.37% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-new.wav
2024-02-23 11:24:18.986491 94.37% [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-message_number.wav] (en:en)
2024-02-23 11:24:18.986491 94.37% [DEBUG] switch_ivr_play_say.c:262 Setting playback volume to 0
2024-02-23 11:24:18.986491 94.37% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:24:19.806485 94.13% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-message_number.wav
2024-02-23 11:24:19.906492 94.13% [DEBUG] switch_ivr_play_say.c:250 Handle say:[1] (en:en)
2024-02-23 11:24:19.906492 94.13% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:24:20.606484 94.10% [DEBUG] switch_ivr_play_say.c:2010 done playing file file_string://digits/1.wav
2024-02-23 11:24:20.706487 94.10% [DEBUG] switch_ivr_play_say.c:70 No language specified - Using [en]
2024-02-23 11:24:20.706487 94.10% [DEBUG] switch_ivr_play_say.c:250 Handle say:[1708686202] (en:en)
2024-02-23 11:24:20.706487 94.10% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:24:23.486488 94.20% [DEBUG] switch_ivr_play_say.c:2010 done playing file file_string://time/today.wav!time/at.wav!digits/11.wav!time/oh.wav!digits/3.wav!time/a-m.wav
2024-02-23 11:24:23.606477 94.20% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:24:34.346465 96.60% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/storage/voicemail/default/pk1betav602.astppbilling.org/9669963218/msg_985d99dc-6b5f-4fcd-9675-5ba86461e187.wav
2024-02-23 11:24:34.346465 96.60% [DEBUG] switch_ivr_play_say.c:70 No language specified - Using [en]
2024-02-23 11:24:34.346465 96.60% [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-listen_to_recording.wav] (en:en)
2024-02-23 11:24:34.346465 96.60% [DEBUG] switch_ivr_play_say.c:262 Setting playback volume to 0
2024-02-23 11:24:34.346465 96.60% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:24:35.566485 97.00% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-listen_to_recording.wav
2024-02-23 11:24:35.686463 97.00% [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-press.wav] (en:en)
2024-02-23 11:24:35.686463 97.00% [DEBUG] switch_ivr_play_say.c:262 Setting playback volume to 0
2024-02-23 11:24:35.686463 97.00% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:24:36.086463 97.00% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-press.wav
2024-02-23 11:24:36.186505 97.00% [DEBUG] switch_ivr_play_say.c:250 Handle say:[0] (en:en)
2024-02-23 11:24:36.186505 97.00% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:24:36.966511 97.00% [DEBUG] switch_ivr_play_say.c:2010 done playing file file_string://digits/0.wav
2024-02-23 11:24:37.086484 97.00% [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-save_recording.wav] (en:en)
2024-02-23 11:24:37.086484 97.00% [DEBUG] switch_ivr_play_say.c:262 Setting playback volume to 0
2024-02-23 11:24:37.086484 97.00% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:24:38.226489 97.03% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-save_recording.wav
2024-02-23 11:24:38.326490 97.03% [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-press.wav] (en:en)
2024-02-23 11:24:38.326490 97.03% [DEBUG] switch_ivr_play_say.c:262 Setting playback volume to 0
2024-02-23 11:24:38.326490 97.03% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:24:38.726502 97.07% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-press.wav
2024-02-23 11:24:38.846485 97.07% [DEBUG] switch_ivr_play_say.c:250 Handle say:[2] (en:en)
2024-02-23 11:24:38.846485 97.07% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:24:39.486463 96.97% [DEBUG] switch_ivr_play_say.c:2010 done playing file file_string://digits/2.wav
2024-02-23 11:24:39.586491 96.97% [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-delete_recording.wav] (en:en)
2024-02-23 11:24:39.586491 96.97% [DEBUG] switch_ivr_play_say.c:262 Setting playback volume to 0
2024-02-23 11:24:39.586491 96.97% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:24:40.706485 96.93% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-delete_recording.wav
2024-02-23 11:24:40.806493 96.93% [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-press.wav] (en:en)
2024-02-23 11:24:40.806493 96.93% [DEBUG] switch_ivr_play_say.c:262 Setting playback volume to 0
2024-02-23 11:24:40.806493 96.93% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:24:41.206512 96.93% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-press.wav
2024-02-23 11:24:41.326463 96.93% [DEBUG] switch_ivr_play_say.c:250 Handle say:[7] (en:en)
2024-02-23 11:24:41.326463 96.93% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:24:42.126474 96.83% [DEBUG] switch_ivr_play_say.c:2010 done playing file file_string://digits/7.wav
2024-02-23 11:24:42.226520 96.83% [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-forward_to_email.wav] (en:en)
2024-02-23 11:24:42.226520 96.83% [DEBUG] switch_ivr_play_say.c:262 Setting playback volume to 0
2024-02-23 11:24:42.226520 96.83% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:24:44.006493 96.77% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-forward_to_email.wav
2024-02-23 11:24:44.126484 96.77% [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-press.wav] (en:en)
2024-02-23 11:24:44.126484 96.77% [DEBUG] switch_ivr_play_say.c:262 Setting playback volume to 0
2024-02-23 11:24:44.126484 96.77% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:24:44.526483 96.80% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-press.wav
2024-02-23 11:24:44.646600 96.80% [DEBUG] switch_ivr_play_say.c:250 Handle say:[4] (en:en)
2024-02-23 11:24:44.646600 96.80% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:24:45.346465 96.80% [DEBUG] switch_ivr_play_say.c:2010 done playing file file_string://digits/4.wav
2024-02-23 11:24:45.446487 96.77% [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-return_call.wav] (en:en)
2024-02-23 11:24:45.446487 96.77% [DEBUG] switch_ivr_play_say.c:262 Setting playback volume to 0
2024-02-23 11:24:45.446487 96.77% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:24:46.606464 96.80% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-return_call.wav
2024-02-23 11:24:46.706470 96.80% [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-press.wav] (en:en)
2024-02-23 11:24:46.706470 96.80% [DEBUG] switch_ivr_play_say.c:262 Setting playback volume to 0
2024-02-23 11:24:46.706470 96.80% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:24:47.106488 96.80% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-press.wav
2024-02-23 11:24:47.226473 96.80% [DEBUG] switch_ivr_play_say.c:250 Handle say:[5] (en:en)
2024-02-23 11:24:47.226473 96.80% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:24:48.006472 96.83% [DEBUG] switch_ivr_play_say.c:2010 done playing file file_string://digits/5.wav
2024-02-23 11:24:48.106506 96.83% [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-to_forward.wav] (en:en)
2024-02-23 11:24:48.106506 96.83% [DEBUG] switch_ivr_play_say.c:262 Setting playback volume to 0
2024-02-23 11:24:48.106506 96.83% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:24:49.366510 96.87% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-to_forward.wav
2024-02-23 11:24:49.486489 97.10% [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-press.wav] (en:en)
2024-02-23 11:24:49.486489 97.10% [DEBUG] switch_ivr_play_say.c:262 Setting playback volume to 0
2024-02-23 11:24:49.486489 97.10% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:24:49.886504 97.10% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-press.wav
2024-02-23 11:24:50.006463 97.10% [DEBUG] switch_ivr_play_say.c:250 Handle say:[8] (en:en)
2024-02-23 11:24:50.006463 97.10% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:24:50.606463 97.07% [DEBUG] switch_ivr_play_say.c:2010 done playing file file_string://digits/8.wav
2024-02-23 11:24:50.706464 97.07% [NOTICE] sofia.c:1065 Hangup sofia/default/9669963218@pk1betav602.astppbilling.org:5078 [CS_EXECUTE] [NORMAL_CLEARING]
2024-02-23 11:24:50.706464 97.07% [DEBUG] mod_voicemail.c:1925 Update MWI: Processing for 9669963218@pk1betav602.astppbilling.org in inbox
2024-02-23 11:24:50.706464 97.07% [DEBUG] mod_voicemail.c:1950 Update MWI: Messages Waiting yes
2024-02-23 11:24:50.706464 97.07% [DEBUG] mod_voicemail.c:1951 Update MWI: Update Reason PURGE
2024-02-23 11:24:50.706464 97.07% [DEBUG] mod_voicemail.c:1952 Update MWI: Message Account 9669963218@pk1betav602.astppbilling.org
2024-02-23 11:24:50.706464 97.07% [DEBUG] mod_voicemail.c:1953 Update MWI: Voice Message 1/0
2024-02-23 11:24:50.706464 97.07% [DEBUG] switch_core_session.c:2979 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2024-02-23 11:24:50.706464 97.07% [DEBUG] switch_core_state_machine.c:647 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State EXECUTE going to sleep
2024-02-23 11:24:50.706464 97.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) Running State Change CS_HANGUP (Cur 1 Tot 9259)
2024-02-23 11:24:50.706464 97.07% [DEBUG] switch_core_state_machine.c:844 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) Callstate Change ACTIVE -> HANGUP
2024-02-23 11:24:50.706464 97.07% [DEBUG] switch_core_state_machine.c:846 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State HANGUP
2024-02-23 11:24:50.706464 97.07% [DEBUG] mod_sofia.c:469 Channel sofia/default/9669963218@pk1betav602.astppbilling.org:5078 hanging up, cause: NORMAL_CLEARING
2024-02-23 11:24:50.706464 97.07% [DEBUG] switch_core_state_machine.c:59 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 Standard HANGUP, cause: NORMAL_CLEARING
2024-02-23 11:24:50.706464 97.07% [DEBUG] switch_core_state_machine.c:846 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State HANGUP going to sleep
2024-02-23 11:24:50.706464 97.07% [DEBUG] switch_core_state_machine.c:616 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State Change CS_HANGUP -> CS_REPORTING
2024-02-23 11:24:50.706464 97.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) Running State Change CS_REPORTING (Cur 1 Tot 9259)
2024-02-23 11:24:50.706464 97.07% [DEBUG] switch_core_state_machine.c:932 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State REPORTING
2024-02-23 11:24:50.706464 97.07% [INFO] mod_json_cdr.c:272 Process [ccb94ef2-5384-438d-946a-e4e9ef78959d.cdr.json]
2024-02-23 11:24:50.706464 97.07% [DEBUG] switch_core_state_machine.c:168 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 Standard REPORTING, cause: NORMAL_CLEARING
2024-02-23 11:24:50.706464 97.07% [DEBUG] switch_core_state_machine.c:932 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State REPORTING going to sleep
2024-02-23 11:24:50.706464 97.07% [DEBUG] switch_core_state_machine.c:607 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State Change CS_REPORTING -> CS_DESTROY
2024-02-23 11:24:50.706464 97.07% [DEBUG] switch_core_session.c:1744 Session 9259 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) Locked, Waiting on external entities
2024-02-23 11:24:50.706464 97.07% [NOTICE] switch_core_session.c:1762 Session 9259 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) Ended
2024-02-23 11:24:50.706464 97.07% [NOTICE] switch_core_session.c:1766 Close Channel sofia/default/9669963218@pk1betav602.astppbilling.org:5078 [CS_DESTROY]
2024-02-23 11:24:50.706464 97.07% [DEBUG] switch_core_state_machine.c:735 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) Running State Change CS_DESTROY (Cur 0 Tot 9259)
2024-02-23 11:24:50.706464 97.07% [DEBUG] switch_core_state_machine.c:745 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State DESTROY
2024-02-23 11:24:50.706464 97.07% [DEBUG] mod_sofia.c:380 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 SOFIA DESTROY
2024-02-23 11:24:50.706464 97.07% [DEBUG] switch_core_state_machine.c:175 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 Standard DESTROY
2024-02-23 11:24:50.706464 97.07% [DEBUG] switch_core_state_machine.c:745 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State DESTROY going to sleep
2024-02-23 11:25:13.586475 95.13% [NOTICE] switch_channel.c:1142 New Channel sofia/default/9669963218@pk1betav602.astppbilling.org:5078 [53f7c52b-ff08-43b4-94cf-93053b25cf8a]
2024-02-23 11:25:13.586475 95.13% [DEBUG] switch_core_state_machine.c:581 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) Running State Change CS_NEW (Cur 1 Tot 9260)
2024-02-23 11:25:13.586475 95.13% [INFO] sofia.c:10459 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 receiving invite from 223.228.239.129:32416 version: 1.10.10-release 64bit call-id: ZjkxZjU3Mjk0OTE1NjM4MjMwMGQ2ZTk5MDMwN2JjZjk.
2024-02-23 11:25:13.586475 95.13% [DEBUG] sofia.c:10553 verifying acl "default" for ip/port 223.228.239.129:0.
2024-02-23 11:25:13.586475 95.13% [DEBUG] sofia.c:2419 detaching session 53f7c52b-ff08-43b4-94cf-93053b25cf8a
2024-02-23 11:25:13.586475 95.13% [WARNING] sofia_reg.c:1842 SIP auth challenge (INVITE) on sofia profile 'default' for [*737473@pk1betav602.astppbilling.org] from ip 223.228.239.129
2024-02-23 11:25:13.586475 95.13% [DEBUG] switch_core_state_machine.c:600 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State NEW
2024-02-23 11:25:13.926485 95.13% [DEBUG] sofia.c:2532 Re-attaching to session 53f7c52b-ff08-43b4-94cf-93053b25cf8a
2024-02-23 11:25:13.946481 95.13% [INFO] sofia.c:10459 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 receiving invite from 223.228.239.129:32416 version: 1.10.10-release 64bit call-id: ZjkxZjU3Mjk0OTE1NjM4MjMwMGQ2ZTk5MDMwN2JjZjk.
2024-02-23 11:25:13.946481 95.13% [DEBUG] sofia.c:10553 verifying acl "default" for ip/port 223.228.239.129:0.
2024-02-23 11:25:13.946481 95.13% [DEBUG] sofia.c:11674 Setting NAT mode based on via received
2024-02-23 11:25:13.946481 95.13% [DEBUG] sofia.c:7493 Channel sofia/default/9669963218@pk1betav602.astppbilling.org:5078 entering state [received][100]
2024-02-23 11:25:13.946481 95.13% [DEBUG] sofia.c:7503 Remote SDP:
v=0
o=Z 0 0 IN IP4 223.228.239.129
s=Z
c=IN IP4 223.228.239.129
t=0 0
m=audio 8000 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
2024-02-23 11:25:13.946481 95.13% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
2024-02-23 11:25:13.946481 95.13% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
2024-02-23 11:25:13.946481 95.13% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [speex:110:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
2024-02-23 11:25:13.946481 95.13% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [speex:110:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
2024-02-23 11:25:13.946481 95.13% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2024-02-23 11:25:13.946481 95.13% [DEBUG] switch_core_media.c:5588 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2024-02-23 11:25:13.946481 95.13% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2024-02-23 11:25:13.946481 95.13% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2024-02-23 11:25:13.946481 95.13% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2024-02-23 11:25:13.946481 95.13% [DEBUG] switch_core_media.c:5588 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2024-02-23 11:25:13.946481 95.13% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [iLBC:98:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
2024-02-23 11:25:13.946481 95.13% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [iLBC:98:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
2024-02-23 11:25:13.946481 95.13% [DEBUG] switch_core_media.c:5438 Set telephone-event payload to 101@8000
2024-02-23 11:25:13.946481 95.13% [DEBUG] switch_core_media.c:3734 Set Codec sofia/default/9669963218@pk1betav602.astppbilling.org:5078 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
2024-02-23 11:25:13.946481 95.13% [DEBUG] switch_core_codec.c:111 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 Original read codec set to PCMA:8
2024-02-23 11:25:13.946481 95.13% [DEBUG] switch_core_media.c:5798 Set telephone-event payload to 101@8000
2024-02-23 11:25:13.946481 95.13% [DEBUG] switch_core_media.c:5856 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 Set 2833 dtmf send payload to 101 recv payload to 101
2024-02-23 11:25:13.946481 95.13% [DEBUG] sofia.c:7927 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State Change CS_NEW -> CS_INIT
2024-02-23 11:25:13.946481 95.13% [DEBUG] switch_core_state_machine.c:581 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) Running State Change CS_INIT (Cur 1 Tot 9260)
2024-02-23 11:25:13.946481 95.13% [DEBUG] switch_core_state_machine.c:624 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State INIT
2024-02-23 11:25:13.946481 95.13% [DEBUG] mod_sofia.c:97 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 SOFIA INIT
2024-02-23 11:25:13.946481 95.13% [DEBUG] switch_core_state_machine.c:40 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 Standard INIT
2024-02-23 11:25:13.946481 95.13% [DEBUG] switch_core_state_machine.c:48 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State Change CS_INIT -> CS_ROUTING
2024-02-23 11:25:13.946481 95.13% [DEBUG] switch_core_state_machine.c:624 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State INIT going to sleep
2024-02-23 11:25:13.946481 95.13% [DEBUG] switch_core_state_machine.c:581 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) Running State Change CS_ROUTING (Cur 1 Tot 9260)
2024-02-23 11:25:13.946481 95.13% [DEBUG] switch_channel.c:2399 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) Callstate Change DOWN -> RINGING
2024-02-23 11:25:13.946481 95.13% [DEBUG] switch_core_state_machine.c:640 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State ROUTING
2024-02-23 11:25:13.946481 95.13% [DEBUG] mod_sofia.c:158 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 SOFIA ROUTING
2024-02-23 11:25:13.946481 95.13% [DEBUG] switch_core_state_machine.c:230 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 Standard ROUTING
2024-02-23 11:25:13.946481 95.13% [INFO] mod_dialplan_xml.c:639 Processing 9669963218 <9669963218>->*737473 in context default
2024-02-23 11:25:13.966461 95.13% [INFO] switch_cpp.cpp:1465 [ASTPP] USING CACHE
2024-02-23 11:25:13.966461 95.13% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_SYSTEM]1.0
2024-02-23 11:25:13.966461 95.13% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_SYSTEM]1.0
2024-02-23 11:25:13.966461 95.13% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [LOAD_ADDON_CONF] Query :SELECT package_name FROM addons
2024-02-23 11:25:13.966461 95.13% [INFO] switch_cpp.cpp:1465 [ASTPP] [feature_code_call_transfer] Blind Call Flag: 0
2024-02-23 11:25:13.966461 95.13% [INFO] switch_cpp.cpp:1465 [ASTPP] [feature_code_call_transfer] Hunt Destination Number: *737473
2024-02-23 11:25:13.966461 95.13% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CHECK_FEATURE_CODE] Query :SELECT id,feature_action,feature_code from feature_code where feature_action = 'call_transfer_attended' limit 1
2024-02-23 11:25:13.966461 95.13% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CHECK_FEATURE_CODE] Query :SELECT id,feature_action,feature_code from feature_code where feature_action = 'call_transfer' limit 1
2024-02-23 11:25:13.966461 95.13% [INFO] switch_cpp.cpp:1465 [ASTPP] [feature_code_call_transfer] Feature Code Transfer Blind Value :*2
2024-02-23 11:25:13.966461 95.13% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] Dialed number : *737473
2024-02-23 11:25:13.966461 95.13% [DEBUG] switch_cpp.cpp:1465 [ASTPP] [CACHING_DEBUG_ACCESS_NUMBER]1.0
2024-02-23 11:25:13.966461 95.13% [INFO] switch_cpp.cpp:1465 [ASTPP] [Dialplan] VOICEMAIL :
2024-02-23 11:25:13.966461 95.13% [DEBUG] switch_cpp.cpp:1465 [ASTPP] Generated XML:
Dialplan: sofia/default/9669963218@pk1betav602.astppbilling.org:5078 parsing [default->\*737473] continue=false
Dialplan: sofia/default/9669963218@pk1betav602.astppbilling.org:5078 Regex (PASS) [\*737473] destination_number(*737473) =~ /\*737473/ break=on-false
Dialplan: sofia/default/9669963218@pk1betav602.astppbilling.org:5078 Action answer()
Dialplan: sofia/default/9669963218@pk1betav602.astppbilling.org:5078 Action voicemail(check default pk1betav602.astppbilling.org 9669963218)
2024-02-23 11:25:13.966461 95.13% [DEBUG] switch_core_state_machine.c:281 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State Change CS_ROUTING -> CS_EXECUTE
2024-02-23 11:25:13.966461 95.13% [DEBUG] switch_core_state_machine.c:640 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State ROUTING going to sleep
2024-02-23 11:25:13.966461 95.13% [DEBUG] switch_core_state_machine.c:581 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) Running State Change CS_EXECUTE (Cur 1 Tot 9260)
2024-02-23 11:25:13.966461 95.13% [DEBUG] switch_core_state_machine.c:647 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State EXECUTE
2024-02-23 11:25:13.966461 95.13% [DEBUG] mod_sofia.c:213 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 SOFIA EXECUTE
2024-02-23 11:25:13.966461 95.13% [DEBUG] switch_core_state_machine.c:323 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 Standard EXECUTE
EXECUTE [depth=0] sofia/default/9669963218@pk1betav602.astppbilling.org:5078 answer()
2024-02-23 11:25:13.966461 95.13% [DEBUG] switch_core_media.c:8659 AUDIO RTP [sofia/default/9669963218@pk1betav602.astppbilling.org:5078] 172.31.42.21 port 22354 -> 223.228.239.129 port 8000 codec: 8 ms: 20
2024-02-23 11:25:13.966461 95.13% [DEBUG] switch_rtp.c:4373 Starting timer [soft] 160 bytes per 20ms
2024-02-23 11:25:13.966461 95.13% [DEBUG] switch_core_media.c:8972 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 Set 2833 dtmf send payload to 101
2024-02-23 11:25:13.966461 95.13% [DEBUG] switch_core_media.c:8979 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 Set 2833 dtmf receive payload to 101
2024-02-23 11:25:13.966461 95.13% [DEBUG] switch_core_media.c:9002 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 Set rtp dtmf delay to 40
2024-02-23 11:25:13.966461 95.13% [DEBUG] mod_sofia.c:914 Local SDP sofia/default/9669963218@pk1betav602.astppbilling.org:5078:
v=0
o=FreeSWITCH 1708665159 1708665160 IN IP4 35.154.93.145
s=FreeSWITCH
c=IN IP4 35.154.93.145
t=0 0
m=audio 22354 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
2024-02-23 11:25:13.966461 95.13% [DEBUG] sofia.c:7493 Channel sofia/default/9669963218@pk1betav602.astppbilling.org:5078 entering state [completed][200]
2024-02-23 11:25:13.966461 95.13% [NOTICE] mod_dptools.c:1406 Channel [sofia/default/9669963218@pk1betav602.astppbilling.org:5078] has been answered
2024-02-23 11:25:13.966461 95.13% [DEBUG] switch_channel.c:3912 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) Callstate Change RINGING -> ACTIVE
EXECUTE [depth=0] sofia/default/9669963218@pk1betav602.astppbilling.org:5078 voicemail(check default pk1betav602.astppbilling.org 9669963218)
2024-02-23 11:25:13.966461 95.13% [DEBUG] switch_ivr_play_say.c:70 No language specified - Using [en]
2024-02-23 11:25:14.166462 95.13% [DEBUG] sofia.c:7493 Channel sofia/default/9669963218@pk1betav602.astppbilling.org:5078 entering state [ready][200]
2024-02-23 11:25:14.186465 95.13% [DEBUG] switch_rtp.c:7503 Correct audio ip/port confirmed.
2024-02-23 11:25:14.186465 95.13% [DEBUG] switch_ivr_play_say.c:70 No language specified - Using [en]
2024-02-23 11:25:14.206466 95.13% [DEBUG] switch_ivr_play_say.c:250 Handle play-file:[voicemail/vm-enter_pass.wav] (en:en)
2024-02-23 11:25:14.206466 95.13% [DEBUG] switch_ivr_play_say.c:262 Setting playback volume to 0
2024-02-23 11:25:14.206466 95.13% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:25:16.126544 95.07% [DEBUG] switch_ivr_play_say.c:2010 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-enter_pass.wav
2024-02-23 11:25:16.246488 95.07% [DEBUG] switch_ivr_play_say.c:250 Handle say:[#] (en:en)
2024-02-23 11:25:16.246488 95.07% [DEBUG] switch_ivr_play_say.c:1561 Codec Activated L16@8000hz 1 channels 20ms
2024-02-23 11:25:16.906465 95.00% [DEBUG] switch_ivr_play_say.c:2010 done playing file file_string://ascii/35.wav
2024-02-23 11:25:17.666468 95.07% [NOTICE] sofia.c:1065 Hangup sofia/default/9669963218@pk1betav602.astppbilling.org:5078 [CS_EXECUTE] [NORMAL_CLEARING]
2024-02-23 11:25:17.666468 95.07% [DEBUG] switch_core_session.c:2979 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2024-02-23 11:25:17.666468 95.07% [DEBUG] switch_core_state_machine.c:647 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State EXECUTE going to sleep
2024-02-23 11:25:17.666468 95.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) Running State Change CS_HANGUP (Cur 1 Tot 9260)
2024-02-23 11:25:17.666468 95.07% [DEBUG] switch_core_state_machine.c:844 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) Callstate Change ACTIVE -> HANGUP
2024-02-23 11:25:17.666468 95.07% [DEBUG] switch_core_state_machine.c:846 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State HANGUP
2024-02-23 11:25:17.666468 95.07% [DEBUG] mod_sofia.c:469 Channel sofia/default/9669963218@pk1betav602.astppbilling.org:5078 hanging up, cause: NORMAL_CLEARING
2024-02-23 11:25:17.666468 95.07% [DEBUG] switch_core_state_machine.c:59 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 Standard HANGUP, cause: NORMAL_CLEARING
2024-02-23 11:25:17.666468 95.07% [DEBUG] switch_core_state_machine.c:846 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State HANGUP going to sleep
2024-02-23 11:25:17.666468 95.07% [DEBUG] switch_core_state_machine.c:616 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State Change CS_HANGUP -> CS_REPORTING
2024-02-23 11:25:17.666468 95.07% [DEBUG] switch_core_state_machine.c:581 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) Running State Change CS_REPORTING (Cur 1 Tot 9260)
2024-02-23 11:25:17.666468 95.07% [DEBUG] switch_core_state_machine.c:932 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State REPORTING
2024-02-23 11:25:17.666468 95.07% [INFO] mod_json_cdr.c:272 Process [53f7c52b-ff08-43b4-94cf-93053b25cf8a.cdr.json]
2024-02-23 11:25:17.686467 95.07% [DEBUG] switch_core_state_machine.c:168 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 Standard REPORTING, cause: NORMAL_CLEARING
2024-02-23 11:25:17.686467 95.07% [DEBUG] switch_core_state_machine.c:932 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State REPORTING going to sleep
2024-02-23 11:25:17.686467 95.07% [DEBUG] switch_core_state_machine.c:607 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State Change CS_REPORTING -> CS_DESTROY
2024-02-23 11:25:17.686467 95.07% [DEBUG] switch_core_session.c:1744 Session 9260 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) Locked, Waiting on external entities
2024-02-23 11:25:17.686467 95.07% [NOTICE] switch_core_session.c:1762 Session 9260 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) Ended
2024-02-23 11:25:17.686467 95.07% [NOTICE] switch_core_session.c:1766 Close Channel sofia/default/9669963218@pk1betav602.astppbilling.org:5078 [CS_DESTROY]
2024-02-23 11:25:17.686467 95.07% [DEBUG] switch_core_state_machine.c:735 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) Running State Change CS_DESTROY (Cur 0 Tot 9260)
2024-02-23 11:25:17.686467 95.07% [DEBUG] switch_core_state_machine.c:745 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State DESTROY
2024-02-23 11:25:17.686467 95.07% [DEBUG] mod_sofia.c:380 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 SOFIA DESTROY
2024-02-23 11:25:17.686467 95.07% [DEBUG] switch_core_state_machine.c:175 sofia/default/9669963218@pk1betav602.astppbilling.org:5078 Standard DESTROY
2024-02-23 11:25:17.686467 95.07% [DEBUG] switch_core_state_machine.c:745 (sofia/default/9669963218@pk1betav602.astppbilling.org:5078) State DESTROY going to sleep
freeswitch@ip-172-31-42-21>
freeswitch@ip-172-31-42-21>
freeswitch@ip-172-31-42-21> /exit
You have new mail in /var/mail/root
root@ip-172-31-42-21:/opt#
root@ip-172-31-42-21:/opt#