Extension unable to call internally for longer than 32 seconds
We have a strange situation; we have one extension that cannot make internal calls for longer than 32 seconds. For example, if the extension tries to verify its voicemail they get cut off after 32 seconds. See log below: Also if they try to call an extension same result. Iif they make an outside call everything is OK. If somebody, extension or outsides call them no issues. The issue is only internally. Any ideas on how to fix this would be appreciated. Thanks cjb 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:15.397031 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-message_number.wav 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:15.517032 [DEBUG] switch_cpp.cpp:857 getDigits dtmf_buf: 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:15.517032 [DEBUG] switch_ivr.c:3033 No language specified - Using [en] 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:15.537009 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:16.217009 [DEBUG] switch_ivr_play_say.c:1747 done playing file file_string://digits/1.wav 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:16.217009 [DEBUG] switch_ivr.c:3033 No language specified - Using [en] 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:16.237030 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:21.277025 [DEBUG] switch_ivr_play_say.c:1747 done playing file file_string://time/mon-9.wav!digits/15.wav!digits/2.wav!digits/thousand.wav! digits/15.wav!time/at.wav!digits/10.wav!digits/40.wav!digits/2.wav!time/a-m. wav 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:21.277025 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.337022 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/200@192.168.20.153 [BREAK] 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.337022 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/200@192.168.20.153 [BREAK] 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] sofia.c:6627 Channel sofia/internal/200@192.168.20.153 entering state [terminating][0] 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [NOTICE] sofia.c:7543 Hangup sofia/internal/200@192.168.20.153 [CS_EXECUTE] [NORMAL_UNSPECIFIED] 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_channel.c:3242 Send signal sofia/internal/200@192.168.20.153 [KILL] 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/200@192.168.20.153 [BREAK] 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/storage/voicemail/default/192.168.20.153/200/msg_2f5fb b82-d178-499e-ba59-1adaad2452af.wav 2015-10-15 10:45:28.357018 [DEBUG] freeswitch_lua.cpp:377 DBH handle 0x7f50ac075ce0 released. 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_cpp.cpp:1075 sofia/internal/200@192.168.20.153 destroy/unlink session from object 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_core_session.c:2901 sofia/internal/200@192.168.20.153 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_core_state_machine.c:535 (sofia/internal/200@192.168.20.153) State EXECUTE going to sleep 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/200@192.168.20.153) Running State Change CS_HANGUP 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_core_state_machine.c:735 (sofia/internal/200@192.168.20.153) Callstate Change ACTIVE -> HANGUP 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_core_state_machine.c:737 (sofia/internal/200@192.168.20.153) State HANGUP 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] mod_sofia.c:413 Channel sofia/internal/200@192.168.20.153 hanging up, cause: NORMAL_UNSPECIFIED 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_core_state_machine.c:60 sofia/internal/200@192.168.20.153 Standard HANGUP, cause: NORMAL_UNSPECIFIED 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_core_state_machine.c:737 (sofia/internal/200@192.168.20.153) State HANGUP going to sleep 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/200@192.168.20.153) State Change CS_HANGUP -> CS_REPORTING 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/200@192.168.20.153 [BREAK] 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/200@192.168.20.153) Running State Change CS_REPORTING 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_core_state_machine.c:823 (sofia/internal/200@192.168.20.153) State REPORTING 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.377019 [DEBUG] switch_core_state_machine.c:104 sofia/internal/200@192.168.20.153 Standard REPORTING, cause: NORMAL_UNSPECIFIED 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.377019 [DEBUG] switch_core_state_machine.c:823 (sofia/internal/200@192.168.20.153) State REPORTING going to sleep 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.377019 [DEBUG] switch_core_state_machine.c:498 (sofia/internal/200@192.168.20.153) State Change CS_REPORTING -> CS_DESTROY 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.377019 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/200@192.168.20.153 [BREAK] 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.377019 [DEBUG] switch_core_session.c:1623 Session 4 (sofia/internal/200@192.168.20.153) Locked, Waiting on external entities 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.377019 [NOTICE] switch_core_session.c:1641 Session 4 (sofia/internal/200@192.168.20.153) Ended 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.377019 [NOTICE] switch_core_session.c:1645 Close Channel sofia/internal/200@192.168.20.153 [CS_DESTROY] 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.377019 [DEBUG] switch_core_state_machine.c:626 (sofia/internal/200@192.168.20.153) Running State Change CS_DESTROY 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.377019 [DEBUG] switch_core_state_machine.c:636 (sofia/internal/200@192.168.20.153) State DESTROY 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.377019 [DEBUG] mod_sofia.c:323 sofia/internal/200@192.168.20.153 SOFIA DESTROY 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.377019 [DEBUG] switch_core_state_machine.c:111 sofia/internal/200@192.168.20.153 Standard DESTROY 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.377019 [DEBUG] switch_core_state_machine.c:636 (sofia/internal/200@192.168.20.153) State DESTROY going to sleep 2015-10-15 10:45:50.937001 [DEBUG] freeswitch_lua.cpp:360 DBH handle 0x7f50ac075ce0 Connected. 2015-10-15 10:45:50.937001 [NOTICE] switch_cpp.cpp:1328 [voicemail] mailbox: 200@192.168.20.153 messages: 1 2015-10-15 10:45:50.937001 [DEBUG] freeswitch_lua.cpp:377 DBH handle 0x7f50ac075ce0 released. 2015-10-15 10:45:53.677034 [DEBUG] freeswitch_lua.cpp:360 DBH handle 0x7f50ac075ce0 Connected. 2015-10-15 10:45:53.697001 [NOTICE] switch_cpp.cpp:1328 [voicemail] mailbox: 200@192.168.20.153 messages: 0 no messages 2015-10-15 10:45:53.697001 [DEBUG] freeswitch_lua.cpp:377 DBH handle 0x7f50ac075ce0 released.
Turn on your sip trace. FS is probably missing the ACK from the phone. This is an interview question for us for SIP admins, "what does it mean when a call only lasts 30 seconds" On Thu, Oct 15, 2015 at 8:55 AM, Charles Bujold <cjbujold@accra.ca> wrote:
We have a strange situation; we have one extension that cannot make internal calls for longer than 32 seconds.
For example, if the extension tries to verify its voicemail they get cut off after 32 seconds. See log below: Also if they try to call an extension same result. Iif they make an outside call everything is OK. If somebody, extension or outsides call them no issues. The issue is only internally. Any ideas on how to fix this would be appreciated.
Thanks
cjb
9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:15.397031 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/sounds/en/us/callie/voicemail/vm-message_number.wav 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:15.517032 [DEBUG] switch_cpp.cpp:857 getDigits dtmf_buf: 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:15.517032 [DEBUG] switch_ivr.c:3033 No language specified - Using [en] 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:15.537009 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:16.217009 [DEBUG] switch_ivr_play_say.c:1747 done playing file file_string://digits/1.wav 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:16.217009 [DEBUG] switch_ivr.c:3033 No language specified - Using [en] 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:16.237030 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:21.277025 [DEBUG] switch_ivr_play_say.c:1747 done playing file file_string://time/mon-9.wav!digits/15.wav!digits/2.wav!digits/thousand.wav!digits/15.wav!time/at.wav!digits/10.wav!digits/40.wav!digits/2.wav!time/a-m.wav
9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:21.277025 [DEBUG] switch_ivr_play_say.c:1314 Codec Activated L16@8000hz 1 channels 20ms 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.337022 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/200@192.168.20.153 [BREAK] 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.337022 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/200@192.168.20.153 [BREAK] 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] sofia.c:6627 Channel sofia/internal/200@192.168.20.153 entering state [terminating][0] 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [NOTICE] sofia.c:7543 Hangup sofia/internal/200@192.168.20.153 [CS_EXECUTE] [NORMAL_UNSPECIFIED] 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_channel.c:3242 Send signal sofia/internal/200@192.168.20.153 [KILL] 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/200@192.168.20.153 [BREAK] 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_ivr_play_say.c:1747 done playing file /usr/local/freeswitch/storage/voicemail/default/ 192.168.20.153/200/msg_2f5fbb82-d178-499e-ba59-1adaad2452af.wav 2015-10-15 10:45:28.357018 [DEBUG] freeswitch_lua.cpp:377 DBH handle 0x7f50ac075ce0 released. 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_cpp.cpp:1075 sofia/internal/200@192.168.20.153 destroy/unlink session from object 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_core_session.c:2901 sofia/internal/200@192.168.20.153 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_core_state_machine.c:535 (sofia/internal/200@192.168.20.153) State EXECUTE going to sleep 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/200@192.168.20.153) Running State Change CS_HANGUP 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_core_state_machine.c:735 (sofia/internal/200@192.168.20.153) Callstate Change ACTIVE -> HANGUP 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_core_state_machine.c:737 (sofia/internal/200@192.168.20.153) State HANGUP 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] mod_sofia.c:413 Channel sofia/internal/200@192.168.20.153 hanging up, cause: NORMAL_UNSPECIFIED 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_core_state_machine.c:60 sofia/internal/200@192.168.20.153 Standard HANGUP, cause: NORMAL_UNSPECIFIED 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_core_state_machine.c:737 (sofia/internal/200@192.168.20.153) State HANGUP going to sleep 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/200@192.168.20.153) State Change CS_HANGUP -> CS_REPORTING 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/200@192.168.20.153 [BREAK] 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/200@192.168.20.153) Running State Change CS_REPORTING 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.357018 [DEBUG] switch_core_state_machine.c:823 (sofia/internal/200@192.168.20.153) State REPORTING 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.377019 [DEBUG] switch_core_state_machine.c:104 sofia/internal/200@192.168.20.153 Standard REPORTING, cause: NORMAL_UNSPECIFIED 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.377019 [DEBUG] switch_core_state_machine.c:823 (sofia/internal/200@192.168.20.153) State REPORTING going to sleep 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.377019 [DEBUG] switch_core_state_machine.c:498 (sofia/internal/200@192.168.20.153) State Change CS_REPORTING -> CS_DESTROY 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.377019 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/200@192.168.20.153 [BREAK] 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.377019 [DEBUG] switch_core_session.c:1623 Session 4 (sofia/internal/200@192.168.20.153) Locked, Waiting on external entities 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.377019 [NOTICE] switch_core_session.c:1641 Session 4 (sofia/internal/200@192.168.20.153) Ended 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.377019 [NOTICE] switch_core_session.c:1645 Close Channel sofia/internal/200@192.168.20.153 [CS_DESTROY] 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.377019 [DEBUG] switch_core_state_machine.c:626 (sofia/internal/200@192.168.20.153) Running State Change CS_DESTROY 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.377019 [DEBUG] switch_core_state_machine.c:636 (sofia/internal/200@192.168.20.153) State DESTROY 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.377019 [DEBUG] mod_sofia.c:323 sofia/internal/200@192.168.20.153 SOFIA DESTROY 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.377019 [DEBUG] switch_core_state_machine.c:111 sofia/internal/200@192.168.20.153 Standard DESTROY 9baee278-79fd-46fb-b945-ffd1035b75de 2015-10-15 10:45:28.377019 [DEBUG] switch_core_state_machine.c:636 (sofia/internal/200@192.168.20.153) State DESTROY going to sleep 2015-10-15 10:45:50.937001 [DEBUG] freeswitch_lua.cpp:360 DBH handle 0x7f50ac075ce0 Connected. 2015-10-15 10:45:50.937001 [NOTICE] switch_cpp.cpp:1328 [voicemail] mailbox: 200@192.168.20.153 messages: 1 2015-10-15 10:45:50.937001 [DEBUG] freeswitch_lua.cpp:377 DBH handle 0x7f50ac075ce0 released. 2015-10-15 10:45:53.677034 [DEBUG] freeswitch_lua.cpp:360 DBH handle 0x7f50ac075ce0 Connected. 2015-10-15 10:45:53.697001 [NOTICE] switch_cpp.cpp:1328 [voicemail] mailbox: 200@192.168.20.153 messages: 0 no messages 2015-10-15 10:45:53.697001 [DEBUG] freeswitch_lua.cpp:377 DBH handle 0x7f50ac075ce0 released.
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
Official FreeSWITCH Sites http://www.freeswitch.org http://confluence.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
-- Anthony Minessale II ♬ @anthmfs ♬ @FreeSWITCH ♬ ☞ http://freeswitch.org/ ☞ http://cluecon.com/ ☞ http://twitter.com/FreeSWITCH ☞ irc.freenode.net #freeswitch ☞ *http://freeswitch.org/g+ <http://freeswitch.org/g+>* ClueCon Weekly Development Call ☎ sip:888@conference.freeswitch.org ☎ +19193869900 https://www.youtube.com/watch?v=9XXgW34t40s https://www.youtube.com/watch?v=NLaDpGQuZDA
On Thu, Oct 15, 2015 at 1:02 PM, Anthony Minessale < anthony.minessale@gmail.com> wrote:
This is an interview question for us for SIP admins, "what does it mean when a call only lasts 30 seconds"
And then the next question is: "What does it mean when a call lasts only 30 minutes?"
30 minutes sounds like failing reinvite for sesison timer to me.
On Oct 15, 2015, at 2:00 PM, Bob Hartwig <bobjectsfreeswitch@gmail.com> wrote:
On Thu, Oct 15, 2015 at 1:02 PM, Anthony Minessale <anthony.minessale@gmail.com <mailto:anthony.minessale@gmail.com>> wrote: This is an interview question for us for SIP admins, "what does it mean when a call only lasts 30 seconds"
And then the next question is: "What does it mean when a call lasts only 30 minutes?"
participants (4)
-
Anthony Minessale
-
Bob Hartwig
-
Charles Bujold
-
Michael Jerris