[Freeswitch-users] External voicemails cutting off

Michael Collins msc at freeswitch.org
Sat Aug 9 02:49:57 MSD 2014 

I think the stuff people need to see in that log is above the part you
snipped out. I recommend you put the full channel debug log into
pastebin.freeswitch.org with syntax highlighting set to FreeSWITCH Log.
-MC


On Fri, Aug 8, 2014 at 11:17 AM, Allison Walters <AWalters at cawst.org> wrote:

>  We’re having a problem with voicemails from outside our system cutting
> off after 60 seconds.  Internal ones are cutting off at 300 seconds, which
> is what we’ve set it to, so that seems fine.  Things I’ve checked/tried:
>
>
>
> ·         The internal and external "rtp-timeout-sec" values are both set
> to "300"
>
> ·         "record_waste_resources=true" is set in dialplan/default.xml
>
> ·         vm_disk_quota not set anywhere
>
>
>
> And I see the following at the console when this happens:
>
> 2014-08-08 11:46:42.107629 [DEBUG] switch_core_session.c:905 Send signal
> sofia/external/<number at IP snipped> [BREAK]
>
> 2014-08-08 11:46:42.127626 [DEBUG] switch_channel.c:2950
> (sofia/external/<number at IP snipped>) Callstate Change ACTIVE -> HANGUP
>
> 2014-08-08 11:46:42.127626 [NOTICE] sofia.c:711 Hangup
> sofia/external/<number at IP snipped> [CS_EXECUTE] [NORMAL_CLEARING]
>
> 2014-08-08 11:46:42.127626 [DEBUG] switch_channel.c:2973 Send signal
> sofia/external/<number at IP snipped> [KILL]
>
> 2014-08-08 11:46:42.127626 [DEBUG] switch_core_session.c:1210 Send signal
> sofia/external/<number at IP snipped> [BREAK]
>
> 2014-08-08 11:46:42.127626 [DEBUG] switch_ivr_bridge.c:588 BRIDGE THREAD
> DONE [sofia/external/<number at IP snipped>]
>
> 2014-08-08 11:46:42.127626 [DEBUG] switch_ivr_bridge.c:613 Send signal
> loopback/voicemail-a [BREAK]
>
> 2014-08-08 11:46:42.127626 [DEBUG] mod_loopback.c:501 loopback/voicemail-a
> CHANNEL KILL
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_ivr_bridge.c:588 BRIDGE THREAD
> DONE [loopback/voicemail-a]
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_ivr_bridge.c:613 Send signal
> sofia/external/<number at IP snipped> [BREAK]
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_channel.c:2950
> (loopback/voicemail-a) Callstate Change ACTIVE -> HANGUP
>
> 2014-08-08 11:46:42.147629 [NOTICE] switch_ivr_bridge.c:676 Hangup
> loopback/voicemail-a [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_channel.c:2973 Send signal
> loopback/voicemail-a [KILL]
>
> 2014-08-08 11:46:42.147629 [DEBUG] mod_loopback.c:501 loopback/voicemail-a
> CHANNEL KILL
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_core_session.c:1210 Send signal
> loopback/voicemail-a [BREAK]
>
> 2014-08-08 11:46:42.147629 [DEBUG] mod_loopback.c:501 loopback/voicemail-a
> CHANNEL KILL
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_core_state_machine.c:456
> (loopback/voicemail-a) State EXCHANGE_MEDIA going to sleep
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_core_state_machine.c:398
> (loopback/voicemail-a) Running State Change CS_HANGUP
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_core_state_machine.c:638
> (loopback/voicemail-a) State HANGUP
>
> 2014-08-08 11:46:42.147629 [DEBUG] mod_loopback.c:453 loopback/voicemail-a
> CHANNEL HANGUP
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_channel.c:2950
> (loopback/voicemail-b) Callstate Change ACTIVE -> HANGUP
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_ivr_bridge.c:1458
> loopback/voicemail-a skip receive message [UNBRIDGE] (channel is hungup
> already)
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_ivr_bridge.c:1461
> sofia/external/<number at IP snipped> skip receive message [UNBRIDGE]
> (channel is hungup already)
>
> 2014-08-08 11:46:42.147629 [NOTICE] mod_loopback.c:464 Hangup
> loopback/voicemail-b [CS_EXECUTE] [NORMAL_CLEARING]
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_channel.c:2973 Send signal
> loopback/voicemail-b [KILL]
>
> 2014-08-08 11:46:42.147629 [DEBUG] mod_loopback.c:501 loopback/voicemail-b
> CHANNEL KILL
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_core_session.c:1210 Send signal
> loopback/voicemail-b [BREAK]
>
> 2014-08-08 11:46:42.147629 [DEBUG] mod_loopback.c:501 loopback/voicemail-b
> CHANNEL KILL
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_core_state_machine.c:48
> loopback/voicemail-a Standard HANGUP, cause: NORMAL_CLEARING
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_core_state_machine.c:638
> (loopback/voicemail-a) State HANGUP going to sleep
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_core_state_machine.c:429
> (loopback/voicemail-a) State Change CS_HANGUP -> CS_REPORTING
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_core_session.c:1210 Send signal
> loopback/voicemail-a [BREAK]
>
> 2014-08-08 11:46:42.147629 [DEBUG] mod_loopback.c:501 loopback/voicemail-a
> CHANNEL KILL
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_core_state_machine.c:398
> (loopback/voicemail-a) Running State Change CS_REPORTING
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_core_session.c:2559
> sofia/external/<number at IP snipped> skip receive message
> [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_core_state_machine.c:453
> (sofia/external/<number at IP snipped>) State EXECUTE going to sleep
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_core_state_machine.c:398
> (sofia/external/<number at IP snipped>) Running State Change CS_HANGUP
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_core_state_machine.c:720
> (loopback/voicemail-a) State REPORTING
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_core_state_machine.c:92
> loopback/voicemail-a Standard REPORTING, cause: NORMAL_CLEARING
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_core_state_machine.c:720
> (loopback/voicemail-a) State REPORTING going to sleep
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_core_state_machine.c:423
> (loopback/voicemail-a) State Change CS_REPORTING -> CS_DESTROY
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_core_session.c:1210 Send signal
> loopback/voicemail-a [BREAK]
>
> 2014-08-08 11:46:42.147629 [DEBUG] mod_loopback.c:501 loopback/voicemail-a
> CHANNEL KILL
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_core_session.c:1415 Session 16
> (loopback/voicemail-a) Locked, Waiting on external entities
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_core_state_machine.c:638
> (sofia/external/<number at IP snipped>) State HANGUP
>
> 2014-08-08 11:46:42.147629 [DEBUG] mod_sofia.c:477
> sofia/external/<number at IP snipped> Overriding SIP cause 480 with 603 from
> the other leg
>
> 2014-08-08 11:46:42.147629 [DEBUG] mod_sofia.c:483 Channel
> sofia/external/<number at IP snipped> hanging up, cause: NORMAL_CLEARING
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_core_state_machine.c:48
> sofia/external/<number at IP snipped> Standard HANGUP, cause: NORMAL_CLEARING
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_core_state_machine.c:638
> (sofia/external/<number at IP snipped>) State HANGUP going to sleep
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_core_state_machine.c:429
> (sofia/external/<number at IP snipped>) State Change CS_HANGUP ->
> CS_REPORTING
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_core_session.c:1210 Send signal
> sofia/external/<number at IP snipped> [BREAK]
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_core_state_machine.c:398
> (sofia/external/<number at IP snipped>) Running State Change CS_REPORTING
>
> 2014-08-08 11:46:42.147629 [DEBUG] switch_core_state_machine.c:720
> (sofia/external/<number at IP snipped>) State REPORTING
>
> 2014-08-08 11:46:42.207636 [DEBUG] switch_core_codec.c:244
> loopback/voicemail-b Restore previous codec PCMU:0.
>
> 2014-08-08 11:46:42.207636 [DEBUG] mod_voicemail.c:2670 Deliver VM to
> 264 at 172.16.2.3
>
> 2014-08-08 11:46:42.307624 [DEBUG] switch_core_state_machine.c:92
> sofia/external/<number at IP snipped> Standard REPORTING, cause:
> NORMAL_CLEARING
>
> 2014-08-08 11:46:42.307624 [DEBUG] switch_core_state_machine.c:720
> (sofia/external/<number at IP snipped>) State REPORTING going to sleep
>
> 2014-08-08 11:46:42.307624 [DEBUG] switch_core_state_machine.c:423
> (sofia/external/<number at IP snipped>) State Change CS_REPORTING ->
> CS_DESTROY
>
> 2014-08-08 11:46:42.307624 [DEBUG] switch_core_session.c:1210 Send signal
> sofia/external/<number at IP snipped> [BREAK]
>
> 2014-08-08 11:46:42.307624 [DEBUG] switch_core_session.c:1415 Session 13
> (sofia/external/<number at IP snipped>) Locked, Waiting on external entities
>
> 2014-08-08 11:46:42.307624 [NOTICE] switch_core_session.c:1433 Session 13
> (sofia/external/<number at IP snipped>) Ended
>
> 2014-08-08 11:46:42.307624 [NOTICE] switch_core_session.c:1437 Close
> Channel sofia/external/<number at IP snipped> [CS_DESTROY]
>
> 2014-08-08 11:46:42.307624 [DEBUG] switch_core_state_machine.c:527
> (sofia/external/<number at IP snipped>) Callstate Change HANGUP -> DOWN
>
> 2014-08-08 11:46:42.307624 [DEBUG] switch_core_state_machine.c:530
> (sofia/external/<number at IP snipped>) Running State Change CS_DESTROY
>
> 2014-08-08 11:46:42.307624 [DEBUG] switch_core_state_machine.c:540
> (sofia/external/<number at IP snipped>) State DESTROY
>
> 2014-08-08 11:46:42.307624 [DEBUG] mod_sofia.c:376
> sofia/external/<number at IP snipped> SOFIA DESTROY
>
> 2014-08-08 11:46:42.307624 [DEBUG] switch_core_state_machine.c:99
> sofia/external/<number at IP snipped> Standard DESTROY
>
> 2014-08-08 11:46:42.307624 [DEBUG] switch_core_state_machine.c:540
> (sofia/external/<number at IP snipped>) State DESTROY going to sleep
>
> 2014-08-08 11:46:51.387663 [DEBUG] switch_utils.c:896 Emailed file
> [/tmp/mail.1407520002da02] to [<email snipped>]
>
> 2014-08-08 11:46:51.387663 [DEBUG] mod_voicemail.c:2860 Sending message to
> <email snipped>
>
> 2014-08-08 11:46:51.387663 [DEBUG] switch_core_session.c:2559
> loopback/voicemail-b skip receive message [APPLICATION_EXEC_COMPLETE]
> (channel is hungup already)
>
> 2014-08-08 11:46:51.387663 [DEBUG] switch_core_state_machine.c:453
> (loopback/voicemail-b) State EXECUTE going to sleep
>
> 2014-08-08 11:46:51.387663 [DEBUG] switch_core_state_machine.c:398
> (loopback/voicemail-b) Running State Change CS_HANGUP
>
> 2014-08-08 11:46:51.387663 [DEBUG] switch_core_state_machine.c:638
> (loopback/voicemail-b) State HANGUP
>
> 2014-08-08 11:46:51.387663 [DEBUG] mod_loopback.c:453 loopback/voicemail-b
> CHANNEL HANGUP
>
> 2014-08-08 11:46:51.387663 [DEBUG] switch_core_state_machine.c:48
> loopback/voicemail-b Standard HANGUP, cause: NORMAL_CLEARING
>
> 2014-08-08 11:46:51.387663 [DEBUG] switch_core_state_machine.c:638
> (loopback/voicemail-b) State HANGUP going to sleep
>
> 2014-08-08 11:46:51.387663 [DEBUG] switch_core_state_machine.c:429
> (loopback/voicemail-b) State Change CS_HANGUP -> CS_REPORTING
>
> 2014-08-08 11:46:51.387663 [DEBUG] switch_core_session.c:1210 Send signal
> loopback/voicemail-b [BREAK]
>
> 2014-08-08 11:46:51.387663 [DEBUG] mod_loopback.c:501 loopback/voicemail-b
> CHANNEL KILL
>
> 2014-08-08 11:46:51.387663 [DEBUG] switch_core_state_machine.c:398
> (loopback/voicemail-b) Running State Change CS_REPORTING
>
> 2014-08-08 11:46:51.387663 [DEBUG] switch_core_state_machine.c:720
> (loopback/voicemail-b) State REPORTING
>
> 2014-08-08 11:46:51.387663 [NOTICE] switch_core_session.c:1433 Session 16
> (loopback/voicemail-a) Ended
>
> 2014-08-08 11:46:51.387663 [NOTICE] switch_core_session.c:1437 Close
> Channel loopback/voicemail-a [CS_DESTROY]
>
> 2014-08-08 11:46:51.387663 [DEBUG] switch_core_state_machine.c:527
> (loopback/voicemail-a) Callstate Change HANGUP -> DOWN
>
> 2014-08-08 11:46:51.387663 [DEBUG] switch_core_state_machine.c:530
> (loopback/voicemail-a) Running State Change CS_DESTROY
>
> 2014-08-08 11:46:51.387663 [DEBUG] switch_core_state_machine.c:540
> (loopback/voicemail-a) State DESTROY
>
> 2014-08-08 11:46:51.387663 [DEBUG] switch_core_state_machine.c:99
> loopback/voicemail-a Standard DESTROY
>
> 2014-08-08 11:46:51.387663 [DEBUG] switch_core_state_machine.c:540
> (loopback/voicemail-a) State DESTROY going to sleep
>
> 2014-08-08 11:46:51.507626 [DEBUG] switch_core_state_machine.c:92
> loopback/voicemail-b Standard REPORTING, cause: NORMAL_CLEARING
>
> 2014-08-08 11:46:51.507626 [DEBUG] switch_core_state_machine.c:720
> (loopback/voicemail-b) State REPORTING going to sleep
>
> 2014-08-08 11:46:51.507626 [DEBUG] switch_core_state_machine.c:423
> (loopback/voicemail-b) State Change CS_REPORTING -> CS_DESTROY
>
> 2014-08-08 11:46:51.507626 [DEBUG] switch_core_session.c:1210 Send signal
> loopback/voicemail-b [BREAK]
>
> 2014-08-08 11:46:51.507626 [DEBUG] mod_loopback.c:501 loopback/voicemail-b
> CHANNEL KILL
>
> 2014-08-08 11:46:51.507626 [DEBUG] switch_core_session.c:1415 Session 17
> (loopback/voicemail-b) Locked, Waiting on external entities
>
> 2014-08-08 11:46:51.507626 [NOTICE] switch_core_session.c:1433 Session 17
> (loopback/voicemail-b) Ended
>
> 2014-08-08 11:46:51.507626 [NOTICE] switch_core_session.c:1437 Close
> Channel loopback/voicemail-b [CS_DESTROY]
>
> 2014-08-08 11:46:51.507626 [DEBUG] switch_core_state_machine.c:527
> (loopback/voicemail-b) Callstate Change HANGUP -> DOWN
>
> 2014-08-08 11:46:51.507626 [DEBUG] switch_core_state_machine.c:530
> (loopback/voicemail-b) Running State Change CS_DESTROY
>
> 2014-08-08 11:46:51.507626 [DEBUG] switch_core_state_machine.c:540
> (loopback/voicemail-b) State DESTROY
>
> 2014-08-08 11:46:51.507626 [DEBUG] switch_core_state_machine.c:99
> loopback/voicemail-b Standard DESTROY
>
> 2014-08-08 11:46:51.507626 [DEBUG] switch_core_state_machine.c:540
> (loopback/voicemail-b) State DESTROY going to sleep
>
>
>
>
>
> Any help would be appreciated!
>
>
>
>
>
> --
>
> *Allison Walters*
>
> *IT Coordinator*
>
> CAWST - Centre for Affordable Water and Sanitation Technology
>
> 424 Aviation Road NE, Calgary, Alberta, T2E 8H6, Canada
>
> tel: +1-403-243-3285 ext.264
>
> web: www.cawst.org
>
>
>
> *Join us in reaching 20 million people by 2020 with safe drinking water
> and sanitation. *
>
>
>
> _________________________________________________________________________
> Professional FreeSWITCH Consulting Services:
> consulting at freeswitch.org
> http://www.freeswitchsolutions.com
>
> 
> 
>
> Official FreeSWITCH Sites
> http://www.freeswitch.org
> http://wiki.freeswitch.org
> http://www.cluecon.com
>
> FreeSWITCH-users mailing list
> FreeSWITCH-users at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
> http://www.freeswitch.org
>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20140808/85dc9c6c/attachment-0001.html

Join us at ClueCon 2016 Aug 8-12, 2016
More information about the FreeSWITCH-users mailing list