[Freeswitch-users] Client gets hang-up after 32 seconds

Ken Rice krice at freeswitch.org
Mon Apr 27 18:12:05 MSD 2015 

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 at freeswitch.org for
paid immediate support.

Thank
K



On 4/27/15, 8:33 AM, "Charles Bujold" <cjbujold at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 192.168.20.153 skip receive
> message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
> 
> 
> _________________________________________________________________________
> Professional FreeSWITCH Consulting Services:
> consulting at 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 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

-- 
Ken
http://www.FreeSWITCH.org
http://www.ClueCon.com
http://www.OSTAG.org
irc.freenode.net #freeswitch
Twitter: @FreeSWITCH


-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20150427/5dd5cf15/attachment.html

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