Client gets hang-up after 32 seconds
We have an extension that we can call and can talk with no problems. However if the extension calls us, he gets connected and we can only talk for 32 seconds before the call gets terminated. We looked at the log and are unable to identify the reason why he cannot call us but that we can call him. The error seems to be that when he calls Freeswitch for some reason sets a timeout of 30 seconds (Setting leg timeout to 30) See log below. Please help. How can we fix this? Thanks Charles 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 o=FreeSWITCH 1430114648 1430114650 IN IP4 156.34.240.101 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 s=FreeSWITCH 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 c=IN IP4 156.34.240.101 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 t=0 0 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 m=audio 25974 RTP/AVP 0 101 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 a=rtpmap:0 PCMU/8000 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 a=rtpmap:101 telephone-event/8000 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 a=fmtp:101 0-16 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 a=ptime:20 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 a=sendrecv 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:04.785852 [DEBUG] switch_core_session.c:908 Send signal sofia/internal/425@192.168.20.153 [BREAK] 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:04.785852 [DEBUG] switch_core_session.c:1053 Send signal sofia/internal/425@192.168.20.153 [BREAK] 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:04.785852 [NOTICE] switch_ivr_originate.c:3522 Channel [sofia/internal/425@192.168.20.153] has been answered 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:04.785852 [DEBUG] switch_channel.c:3689 (sofia/internal/425@192.168.20.153) Callstate Change EARLY -> ACTIVE 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:04.785852 [DEBUG] sofia.c:6614 Channel sofia/internal/425@192.168.20.153 entering state [completed][200] 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:04.785852 [DEBUG] switch_ivr_originate.c:3580 Originate Resulted in Success: [sofia/internal/sip:200@192.168.20.150:5060] 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:04.785852 [DEBUG] switch_ivr_originate.c:2847 sofia/internal/sip:200@192.168.20.150:5060 Setting leg timeout to 30 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:04.785852 [DEBUG] switch_ivr_originate.c:3580 Originate Resulted in Success: [sofia/internal/sip:200@192.168.20.150:5060] b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:04.785852 [DEBUG] switch_core_session.c:908 Send signal sofia/internal/sip:200@192.168.20.150:5060 [BREAK] 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:04.785852 [DEBUG] switch_core_session.c:908 Send signal sofia/internal/425@192.168.20.153 [BREAK] b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:04.785852 [DEBUG] switch_ivr_bridge.c:1465 (sofia/internal/sip:200@192.168.20.150:5060) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:04.785852 [DEBUG] switch_core_session.c:1388 Send signal sofia/internal/sip:200@192.168.20.150:5060 [BREAK] b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:04.785852 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/sip:200@192.168.20.150:5060) Running State Change CS_EXCHANGE_MEDIA b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:04.785852 [DEBUG] switch_core_state_machine.c:538 (sofia/internal/sip:200@192.168.20.150:5060) State EXCHANGE_MEDIA b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:04.785852 [DEBUG] mod_sofia.c:594 SOFIA EXCHANGE_MEDIA b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:04.845827 [DEBUG] switch_rtp.c:5853 Correct ip/port confirmed. 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:36.785826 [DEBUG] switch_core_session.c:1053 Send signal sofia/internal/425@192.168.20.153 [BREAK] 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:36.785826 [DEBUG] switch_core_session.c:1053 Send signal sofia/internal/425@192.168.20.153 [BREAK] 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:36.805822 [DEBUG] sofia.c:6614 Channel sofia/internal/425@192.168.20.153 entering state [terminating][0] 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:36.805822 [NOTICE] sofia.c:7530 Hangup sofia/internal/425@192.168.20.153 [CS_EXECUTE] [NORMAL_UNSPECIFIED] 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:36.805822 [DEBUG] switch_channel.c:3222 Send signal sofia/internal/425@192.168.20.153 [KILL] 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:36.805822 [DEBUG] mod_hash.c:298 Usage for 192.168.20.153_200 is now 0 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:36.805822 [DEBUG] switch_core_session.c:1388 Send signal sofia/internal/425@192.168.20.153 [BREAK] 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:36.805822 [DEBUG] switch_ivr_bridge.c:660 BRIDGE THREAD DONE [sofia/internal/425@192.168.20.153] b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:36.805822 [DEBUG] switch_ivr_bridge.c:690 Send signal sofia/internal/sip:200@192.168.20.150:5060 [BREAK] b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:36.825829 [DEBUG] switch_ivr_bridge.c:579 sofia/internal/425@192.168.20.153 ending bridge by request from write function b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:36.825829 [DEBUG] switch_ivr_bridge.c:660 BRIDGE THREAD DONE [sofia/internal/sip:200@192.168.20.150:5060] 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:36.825829 [DEBUG] switch_ivr_bridge.c:690 Send signal sofia/internal/425@192.168.20.153 [BREAK] b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:36.825829 [NOTICE] switch_ivr_bridge.c:754 Hangup sofia/internal/sip:200@192.168.20.150:5060 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:36.825829 [DEBUG] switch_channel.c:3222 Send signal sofia/internal/sip:200@192.168.20.150:5060 [KILL] b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:36.825829 [DEBUG] switch_core_session.c:1388 Send signal sofia/internal/sip:200@192.168.20.150:5060 [BREAK] b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:36.825829 [DEBUG] switch_core_state_machine.c:538 (sofia/internal/sip:200@192.168.20.150:5060) State EXCHANGE_MEDIA going to sleep b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:36.825829 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/sip:200@192.168.20.150:5060) Running State Change CS_HANGUP b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:36.825829 [DEBUG] switch_core_state_machine.c:735 (sofia/internal/sip:200@192.168.20.150:5060) Callstate Change ACTIVE -> HANGUP b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:36.825829 [DEBUG] switch_ivr_bridge.c:1563 sofia/internal/sip:200@192.168.20.150:5060 skip receive message [UNBRIDGE] (channel is hungup already) 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:36.825829 [DEBUG] switch_ivr_bridge.c:1566 sofia/internal/425@192.168.20.153 skip receive message [UNBRIDGE] (channel is hungup already) b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:36.825829 [DEBUG] switch_core_state_machine.c:737 (sofia/internal/sip:200@192.168.20.150:5060) State HANGUP b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:36.825829 [DEBUG] mod_sofia.c:413 Channel sofia/internal/sip:200@192.168.20.150:5060 hanging up, cause: NORMAL_CLEARING 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:36.825829 [DEBUG] switch_core_session.c:2893 sofia/internal/425@192.168.20.153 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
This is probably a NAT issue where the FS isnt getting that ACK for the 200 OK in the sip messaging. To confirm this enable sip tracing in sofia fs_cli> sofia global siptrace on Also setting high priority on an email to this list is not a desirable thing to do as it will get most people to ignore your emails. If in the future you require immediate attention, I would contact consulting@freeswitch.org for paid immediate support. Thank K On 4/27/15, 8:33 AM, "Charles Bujold" <cjbujold@accra.ca> wrote:
We have an extension that we can call and can talk with no problems. However if the extension calls us, he gets connected and we can only talk for 32 seconds before the call gets terminated. We looked at the log and are unable to identify the reason why he cannot call us but that we can call him. The error seems to be that when he calls Freeswitch for some reason sets a timeout of 30 seconds (Setting leg timeout to 30) See log below.
Please help. How can we fix this? Thanks Charles
6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 o=FreeSWITCH 1430114648 1430114650 IN IP4 156.34.240.101 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 s=FreeSWITCH 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 c=IN IP4 156.34.240.101 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 t=0 0 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 m=audio 25974 RTP/AVP 0 101 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 a=rtpmap:0 PCMU/8000 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 a=rtpmap:101 telephone-event/8000 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 a=fmtp:101 0-16 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 a=ptime:20 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 a=sendrecv 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:04.785852 [DEBUG] switch_core_session.c:908 Send signal sofia/internal/425@192.168.20.153 [BREAK] 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:04.785852 [DEBUG] switch_core_session.c:1053 Send signal sofia/internal/425@192.168.20.153 [BREAK] 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:04.785852 [NOTICE] switch_ivr_originate.c:3522 Channel [sofia/internal/425@192.168.20.153] has been answered 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:04.785852 [DEBUG] switch_channel.c:3689 (sofia/internal/425@192.168.20.153) Callstate Change EARLY -> ACTIVE 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:04.785852 [DEBUG] sofia.c:6614 Channel sofia/internal/425@192.168.20.153 entering state [completed][200] 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:04.785852 [DEBUG] switch_ivr_originate.c:3580 Originate Resulted in Success: [sofia/internal/sip:200@192.168.20.150:5060] 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:04.785852 [DEBUG] switch_ivr_originate.c:2847 sofia/internal/sip:200@192.168.20.150:5060 Setting leg timeout to 30 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:04.785852 [DEBUG] switch_ivr_originate.c:3580 Originate Resulted in Success: [sofia/internal/sip:200@192.168.20.150:5060] b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:04.785852 [DEBUG] switch_core_session.c:908 Send signal sofia/internal/sip:200@192.168.20.150:5060 [BREAK] 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:04.785852 [DEBUG] switch_core_session.c:908 Send signal sofia/internal/425@192.168.20.153 [BREAK] b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:04.785852 [DEBUG] switch_ivr_bridge.c:1465 (sofia/internal/sip:200@192.168.20.150:5060) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:04.785852 [DEBUG] switch_core_session.c:1388 Send signal sofia/internal/sip:200@192.168.20.150:5060 [BREAK] b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:04.785852 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/sip:200@192.168.20.150:5060) Running State Change CS_EXCHANGE_MEDIA b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:04.785852 [DEBUG] switch_core_state_machine.c:538 (sofia/internal/sip:200@192.168.20.150:5060) State EXCHANGE_MEDIA b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:04.785852 [DEBUG] mod_sofia.c:594 SOFIA EXCHANGE_MEDIA b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:04.845827 [DEBUG] switch_rtp.c:5853 Correct ip/port confirmed. 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:36.785826 [DEBUG] switch_core_session.c:1053 Send signal sofia/internal/425@192.168.20.153 [BREAK] 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:36.785826 [DEBUG] switch_core_session.c:1053 Send signal sofia/internal/425@192.168.20.153 [BREAK] 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:36.805822 [DEBUG] sofia.c:6614 Channel sofia/internal/425@192.168.20.153 entering state [terminating][0] 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:36.805822 [NOTICE] sofia.c:7530 Hangup sofia/internal/425@192.168.20.153 [CS_EXECUTE] [NORMAL_UNSPECIFIED] 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:36.805822 [DEBUG] switch_channel.c:3222 Send signal sofia/internal/425@192.168.20.153 [KILL] 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:36.805822 [DEBUG] mod_hash.c:298 Usage for 192.168.20.153_200 is now 0 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:36.805822 [DEBUG] switch_core_session.c:1388 Send signal sofia/internal/425@192.168.20.153 [BREAK] 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:36.805822 [DEBUG] switch_ivr_bridge.c:660 BRIDGE THREAD DONE [sofia/internal/425@192.168.20.153] b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:36.805822 [DEBUG] switch_ivr_bridge.c:690 Send signal sofia/internal/sip:200@192.168.20.150:5060 [BREAK] b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:36.825829 [DEBUG] switch_ivr_bridge.c:579 sofia/internal/425@192.168.20.153 ending bridge by request from write function b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:36.825829 [DEBUG] switch_ivr_bridge.c:660 BRIDGE THREAD DONE [sofia/internal/sip:200@192.168.20.150:5060] 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:36.825829 [DEBUG] switch_ivr_bridge.c:690 Send signal sofia/internal/425@192.168.20.153 [BREAK] b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:36.825829 [NOTICE] switch_ivr_bridge.c:754 Hangup sofia/internal/sip:200@192.168.20.150:5060 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:36.825829 [DEBUG] switch_channel.c:3222 Send signal sofia/internal/sip:200@192.168.20.150:5060 [KILL] b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:36.825829 [DEBUG] switch_core_session.c:1388 Send signal sofia/internal/sip:200@192.168.20.150:5060 [BREAK] b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:36.825829 [DEBUG] switch_core_state_machine.c:538 (sofia/internal/sip:200@192.168.20.150:5060) State EXCHANGE_MEDIA going to sleep b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:36.825829 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/sip:200@192.168.20.150:5060) Running State Change CS_HANGUP b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:36.825829 [DEBUG] switch_core_state_machine.c:735 (sofia/internal/sip:200@192.168.20.150:5060) Callstate Change ACTIVE -> HANGUP b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:36.825829 [DEBUG] switch_ivr_bridge.c:1563 sofia/internal/sip:200@192.168.20.150:5060 skip receive message [UNBRIDGE] (channel is hungup already) 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:36.825829 [DEBUG] switch_ivr_bridge.c:1566 sofia/internal/425@192.168.20.153 skip receive message [UNBRIDGE] (channel is hungup already) b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:36.825829 [DEBUG] switch_core_state_machine.c:737 (sofia/internal/sip:200@192.168.20.150:5060) State HANGUP b8e098cc-82a9-4128-992e-a21690707fb3 2015-04-27 10:17:36.825829 [DEBUG] mod_sofia.c:413 Channel sofia/internal/sip:200@192.168.20.150:5060 hanging up, cause: NORMAL_CLEARING 6d0e7ed5-6078-4a31-9d6e-0e7d239c3579 2015-04-27 10:17:36.825829 [DEBUG] switch_core_session.c:2893 sofia/internal/425@192.168.20.153 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
_________________________________________________________________________ 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
-- Ken http://www.FreeSWITCH.org http://www.ClueCon.com http://www.OSTAG.org irc.freenode.net #freeswitch Twitter: @FreeSWITCH
participants (2)
-
Charles Bujold
-
Ken Rice