[Freeswitch-users] Call drops after 30 seconds

[Matthew Ralston]

Hi,

I'm having a problem at the moment with calls being successfully set up, with two-way audio, being terminated by FreeSWITCH after 30 seconds.

Internal calls (i.e. between SIP phones on the same LAN segment as the FreeSWITCH box) work flawlessly.

The problem arises when at least one of the handsets is located elsewhere on the Internet. This behaviour is exhibited under the following circumstances:

- A-leg only call, e.g. to voicemail when the handset is at another location on the Internet
- A-leg-B-leg call if one or both of the handsets are at another location on the Internet
- Inbound calls from our external SIP provider
- Outbound calls to our external SIP provider

So it is obvious that the problem is related to the SIP going via the Internet, but I'm having trouble understanding why.

Whilst debugging this problem I have placed the FreeSWITCH box is in the DMZ on our router, so there should not be any ports blocked. The FreeSWITCH box itself is not running a software firewall.

The calls themselves are absolutely fine for the first 30 seconds - each party can hear the other talking fine.

The fact that the call is consistently dropped after 30 seconds (give or take a second or two for PDD) suggests that some timeout is being triggered.

When FreeSWITCH terminates the call, the following is logged to the console:

2011-06-22 13:33:50.514941 [DEBUG] sofia.c:4787 Channel sofia/internal/1006 at public.ip.removed entering state [terminating][0]
2011-06-22 13:33:50.514941 [DEBUG] switch_channel.c:2641 (sofia/internal/1006 at public.ip.removed) Callstate Change ACTIVE -> HANGUP
2011-06-22 13:33:50.514941 [NOTICE] sofia.c:5508 Hangup sofia/internal/1006 at public.ip.removed [CS_EXECUTE] [NORMAL_UNSPECIFIED]
2011-06-22 13:33:50.514941 [DEBUG] switch_channel.c:2657 Send signal sofia/internal/1006 at public.ip.removed [KILL]
2011-06-22 13:33:50.514941 [DEBUG] switch_core_session.c:1118 Send signal sofia/internal/1006 at public.ip.removed [BREAK]
2011-06-22 13:33:50.534966 [DEBUG] switch_ivr_play_say.c:1649 done playing file
2011-06-22 13:33:50.625988 [DEBUG] switch_ivr_play_say.c:244 Handle play-file:[voicemail/vm-press.wav] (en:en)
2011-06-22 13:33:50.727027 [DEBUG] switch_core_session.c:2063 sofia/internal/1006 at public.ip.removed skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2011-06-22 13:33:50.727027 [DEBUG] switch_core_state_machine.c:371 (sofia/internal/1006 at public.ip.removed) State EXECUTE going to sleep
2011-06-22 13:33:50.727027 [DEBUG] switch_core_state_machine.c:325 (sofia/internal/1006 at public.ip.removed) Running State Change CS_HANGUP
2011-06-22 13:33:50.727027 [DEBUG] switch_core_state_machine.c:565 (sofia/internal/1006 at public.ip.removed) State HANGUP
2011-06-22 13:33:50.727027 [DEBUG] mod_sofia.c:458 Channel sofia/internal/1006 at public.ip.removed hanging up, cause: NORMAL_UNSPECIFIED
2011-06-22 13:33:50.727027 [DEBUG] switch_core_state_machine.c:46 sofia/internal/1006 at public.ip.removed Standard HANGUP, cause: NORMAL_UNSPECIFIED
2011-06-22 13:33:50.727027 [DEBUG] switch_core_state_machine.c:565 (sofia/internal/1006 at public.ip.removed) State HANGUP going to sleep
2011-06-22 13:33:50.727027 [DEBUG] switch_core_state_machine.c:356 (sofia/internal/1006 at public.ip.removed) State Change CS_HANGUP -> CS_REPORTING
2011-06-22 13:33:50.727027 [DEBUG] switch_core_session.c:1118 Send signal sofia/internal/1006 at public.ip.removed [BREAK]
2011-06-22 13:33:50.727027 [DEBUG] switch_core_state_machine.c:325 (sofia/internal/1006 at public.ip.removed) Running State Change CS_REPORTING
2011-06-22 13:33:50.727027 [DEBUG] switch_core_state_machine.c:625 (sofia/internal/1006 at public.ip.removed) State REPORTING
2011-06-22 13:33:50.740064 [DEBUG] switch_core_state_machine.c:53 sofia/internal/1006 at public.ip.removed Standard REPORTING, cause: NORMAL_UNSPECIFIED
2011-06-22 13:33:50.740064 [DEBUG] switch_core_state_machine.c:625 (sofia/internal/1006 at public.ip.removed) State REPORTING going to sleep
2011-06-22 13:33:50.740064 [DEBUG] switch_core_state_machine.c:350 (sofia/internal/1006 at public.ip.removed) State Change CS_REPORTING -> CS_DESTROY
2011-06-22 13:33:50.740064 [DEBUG] switch_core_session.c:1118 Send signal sofia/internal/1006 at public.ip.removed [BREAK]
2011-06-22 13:33:50.740064 [DEBUG] switch_core_session.c:1290 Session 5 (sofia/internal/1006 at public.ip.removed) Locked, Waiting on external entities
2011-06-22 13:33:50.740064 [NOTICE] switch_core_session.c:1308 Session 5 (sofia/internal/1006 at public.ip.removed) Ended
2011-06-22 13:33:50.740064 [NOTICE] switch_core_session.c:1310 Close Channel sofia/internal/1006 at public.ip.removed [CS_DESTROY]
2011-06-22 13:33:50.740064 [DEBUG] switch_core_state_machine.c:454 (sofia/internal/1006 at public.ip.removed) Callstate Change HANGUP -> DOWN
2011-06-22 13:33:50.740064 [DEBUG] switch_core_state_machine.c:457 (sofia/internal/1006 at public.ip.removed) Running State Change CS_DESTROY
2011-06-22 13:33:50.740064 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/1006 at public.ip.removed) State DESTROY
2011-06-22 13:33:50.740064 [DEBUG] mod_sofia.c:363 sofia/internal/1006 at public.ip.removed SOFIA DESTROY
2011-06-22 13:33:50.780056 [DEBUG] switch_nat.c:570 unmapped public port 31484 protocol UDP to localport 31484
2011-06-22 13:33:50.840070 [DEBUG] switch_nat.c:570 unmapped public port 31485 protocol UDP to localport 31485
2011-06-22 13:33:50.840070 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1006 at public.ip.removed Standard DESTROY
2011-06-22 13:33:50.840070 [DEBUG] switch_core_state_machine.c:467 (sofia/internal/1006 at public.ip.removed) State DESTROY going to sleep

The above example was from an externally situated SIP phone ringing voicemail (4000) on FreeSWITCH.

I have experimented changing various timers and timeouts in the config of FreeSWITCH (one at a time, being careful to put them back afterwards!) but been unable to resolve the issue.

Incidentally, we have no long term intention of running off-site SIP phones with the PBX and I'm hoping not to have to leave it in the DMZ either, it's just like that for debugging. What is a real issue is the calls to our external SIP provider (i.e. outbound calls) being dropped.

Any suggestions would be greatly appreciated.

Thanks,

Matthew Ralston
Web Developer & IT Consultant

matt at mralston.co.uk
www.mralston.com