FREEPBX Call Timeout


(United Kingdom) #1

Hi,

Please could someone help me with this problem. We are using Freepbx for our phone system in school. We have an issue when calls are ‘on hold’ that after 30 minutes the call is disconnected. We need this to be extended because quite often Government departments, Social Services etc mean that calls being on hold for longer than this is quite frequent.

In the Asterix SIP Settings I have changed the RTP Call Timeout settings (on all the fields) to all be 999999 but unfortunately the calls are still being disconnected after 30 minutes.

Can someone please help me fix this as it is becoming quite an issue with the Office staff.

Many Thanks, Shelley


(Communication Technologies) #2

Can you provide the logs and SIP debug for an example call? This could just as easily be a network issues as opposed to a FreePBX setting. If you do a google search on “FreePBX call drops 30 min” see a large quantity of useful posts that can provide additional insights.

https://www.google.com/search?q=freepbx+call+drops+30+minutes+on+hold&sourceid=ie7&rls=com.microsoft:en-US:IE-Address&ie=&oe=&gws_rd=ssl#spf=1591107749654


(United Kingdom) #3

This is in the log file for the time that the call dropped on the 30min time:

[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] bridge_channel.c: Channel PJSIP/204-00000351 left ‘simple_bridge’ basic-bridge <10423a9c-a898-450b-908f-d109b788c3ee>
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] app_macro.c: Spawn extension (macro-dialout-trunk, s, 32) exited non-zero on ‘PJSIP/204-00000351’ in macro ‘dialout-trunk’
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Spawn extension (from-internal, 903002003200, 6) exited non-zero on ‘PJSIP/204-00000351’
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Executing [h@from-internal:1] Macro(“PJSIP/204-00000351”, “hangupcall”) in new stack
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Executing [s@macro-hangupcall:1] GotoIf(“PJSIP/204-00000351”, “1?theend”) in new stack
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx_builtins.c: Goto (macro-hangupcall,s,3)
[2020-06-02 11:21:27] VERBOSE[61120][C-00000268] bridge_channel.c: Channel SIP/toGamma_EndPoint1-0000019e left ‘simple_bridge’ basic-bridge <10423a9c-a898-450b-908f-d109b788c3ee>
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Executing [s@macro-hangupcall:3] ExecIf(“PJSIP/204-00000351”, “0?Set(CDR(recordingfile)=)”) in new stack
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Executing [s@macro-hangupcall:4] NoOp(“PJSIP/204-00000351”, "SIP/toGamma_EndPoint1-0000019e monior file= ") in new stack
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Executing [s@macro-hangupcall:5] AGI(“PJSIP/204-00000351”, “attendedtransfer-rec-restart.php,SIP/toGamma_EndPoint1-0000019e,”) in new stack
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/attendedtransfer-rec-restart.php
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] res_agi.c: <PJSIP/204-00000351>AGI Script attendedtransfer-rec-restart.php completed, returning 0
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Executing [s@macro-hangupcall:6] Hangup(“PJSIP/204-00000351”, “”) in new stack
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] app_macro.c: Spawn extension (macro-hangupcall, s, 6) exited non-zero on ‘PJSIP/204-00000351’ in macro ‘hangupcall’
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Spawn extension (from-internal, h, 1) exited non-zero on ‘PJSIP/204-00000351’
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] app_stack.c: PJSIP/204-00000351 Internal Gosub(crm-hangup,s,1) start
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Executing [s@crm-hangup:1] NoOp(“PJSIP/204-00000351”, “Sending Hangup to CRM”) in new stack
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Executing [s@crm-hangup:2] NoOp(“PJSIP/204-00000351”, “HANGUP CAUSE: 16”) in new stack
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Executing [s@crm-hangup:3] ExecIf(“PJSIP/204-00000351”, “0?Set(__CRM_VOICEMAIL=)”) in new stack
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Executing [s@crm-hangup:4] NoOp(“PJSIP/204-00000351”, “MASTER CHANNEL: 1591091472.1485 = 1591091472.1485”) in new stack
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Executing [s@crm-hangup:5] GotoIf(“PJSIP/204-00000351”, “0?return”) in new stack
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Executing [s@crm-hangup:6] Set(“PJSIP/204-00000351”, “__CRM_HANGUP=1”) in new stack
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Executing [s@crm-hangup:7] AGI(“PJSIP/204-00000351”, “sangomacrm.agi”) in new stack
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
[2020-06-02 11:21:28] VERBOSE[61100][C-00000268] res_agi.c: <PJSIP/204-00000351>AGI Script sangomacrm.agi completed, returning 0
[2020-06-02 11:21:28] VERBOSE[61100][C-00000268] pbx.c: Executing [s@crm-hangup:8] Return(“PJSIP/204-00000351”, “”) in new stack
[2020-06-02 11:21:28] VERBOSE[61100][C-00000268] app_stack.c: Spawn extension (from-internal, h, 1) exited non-zero on ‘PJSIP/204-00000351’
[2020-06-02 11:21:28] VERBOSE[61100][C-00000268] app_stack.c: PJSIP/204-00000351 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=


(Communication Technologies) #4

Did you get the SIP logs?


(Dave Burgess) #5

Grep for that or 61100 in the /var/log/asterisk/full log and see what you can find. The ‘30 minute’ part screams NAT session drop, and is often a symptom of an incomplete RTP path. If everything is configured correctly, a long phone call (like the 2 1/2 hour one I just got off) will work just fine.


(United Kingdom) #6

Sorry for my ignorance - is what I copied and pasted above not the SIPs log? I have no idea. Where should I look to find what you need? I have the administrator password but not sure which log I should look at? The above comes from the Asterix Log Files where I selected ‘full’ in the file option for the time that the call dropped…

Many Thanks, Shelley


(United Kingdom) #7

This is what I see in the ‘full’ log for the exact time that the call was placed (10:51) then when it was disconnected (11:21). I’m sorry, I have no idea what I am looking at to tell me where to check the configuration and what might cause the disconnect after 30mins…

[2020-06-02 10:51:13] VERBOSE[61100][C-00000268] pbx.c: Executing [s@func-apply-sipheaders:3] Set(“SIP/toGamma_EndPoint1-0000019e”, “TECH=SIP”) in new stack
[2020-06-02 10:51:13] VERBOSE[61100][C-00000268] pbx.c: Executing [s@func-apply-sipheaders:4] Set(“SIP/toGamma_EndPoint1-0000019e”, “SIPHEADERKEYS=”) in new stack
[2020-06-02 10:51:13] VERBOSE[61100][C-00000268] pbx.c: Executing [s@func-apply-sipheaders:5] While(“SIP/toGamma_EndPoint1-0000019e”, “0”) in new stack
[2020-06-02 10:51:13] VERBOSE[61100][C-00000268] app_while.c: Jumping to priority 12
[2020-06-02 10:51:13] VERBOSE[61100][C-00000268] pbx.c: Executing [s@func-apply-sipheaders:13] Return(“SIP/toGamma_EndPoint1-0000019e”, “”) in new stack
[2020-06-02 10:51:13] VERBOSE[61100][C-00000268] app_stack.c: Spawn extension (from-trunk-sip-toGamma_EndPoint1, 903002003200, 1) exited non-zero on ‘SIP/toGamma_EndPoint1-0000019e’
[2020-06-02 10:51:13] VERBOSE[61100][C-00000268] app_stack.c: SIP/toGamma_EndPoint1-0000019e Internal Gosub(func-apply-sipheaders,s,1(3)) complete GOSUB_RETVAL=
[2020-06-02 10:51:13] VERBOSE[61100][C-00000268] app_dial.c: Called SIP/toGamma_EndPoint1/443002003200
[2020-06-02 10:51:13] VERBOSE[61100][C-00000268] app_dial.c: SIP/toGamma_EndPoint1-0000019e is making progress passing it to PJSIP/204-00000351
[2020-06-02 10:51:13] VERBOSE[61100][C-00000268] app_dial.c: SIP/toGamma_EndPoint1-0000019e answered PJSIP/204-00000351
[2020-06-02 10:51:13] VERBOSE[61120][C-00000268] bridge_channel.c: Channel SIP/toGamma_EndPoint1-0000019e joined ‘simple_bridge’ basic-bridge <10423a9c-a898-450b-908f-d109b788c3ee>
[2020-06-02 10:51:13] VERBOSE[61100][C-00000268] bridge_channel.c: Channel PJSIP/204-00000351 joined ‘simple_bridge’ basic-bridge <10423a9c-a898-450b-908f-d109b788c3ee>
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] bridge_channel.c: Channel PJSIP/204-00000351 left ‘simple_bridge’ basic-bridge <10423a9c-a898-450b-908f-d109b788c3ee>
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] app_macro.c: Spawn extension (macro-dialout-trunk, s, 32) exited non-zero on ‘PJSIP/204-00000351’ in macro ‘dialout-trunk’
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Spawn extension (from-internal, 903002003200, 6) exited non-zero on ‘PJSIP/204-00000351’
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Executing [h@from-internal:1] Macro(“PJSIP/204-00000351”, “hangupcall”) in new stack
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Executing [s@macro-hangupcall:1] GotoIf(“PJSIP/204-00000351”, “1?theend”) in new stack
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx_builtins.c: Goto (macro-hangupcall,s,3)
[2020-06-02 11:21:27] VERBOSE[61120][C-00000268] bridge_channel.c: Channel SIP/toGamma_EndPoint1-0000019e left ‘simple_bridge’ basic-bridge <10423a9c-a898-450b-908f-d109b788c3ee>
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Executing [s@macro-hangupcall:3] ExecIf(“PJSIP/204-00000351”, “0?Set(CDR(recordingfile)=)”) in new stack
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Executing [s@macro-hangupcall:4] NoOp(“PJSIP/204-00000351”, "SIP/toGamma_EndPoint1-0000019e monior file= ") in new stack
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Executing [s@macro-hangupcall:5] AGI(“PJSIP/204-00000351”, “attendedtransfer-rec-restart.php,SIP/toGamma_EndPoint1-0000019e,”) in new stack
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/attendedtransfer-rec-restart.php
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] res_agi.c: <PJSIP/204-00000351>AGI Script attendedtransfer-rec-restart.php completed, returning 0
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Executing [s@macro-hangupcall:6] Hangup(“PJSIP/204-00000351”, “”) in new stack
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] app_macro.c: Spawn extension (macro-hangupcall, s, 6) exited non-zero on ‘PJSIP/204-00000351’ in macro ‘hangupcall’
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Spawn extension (from-internal, h, 1) exited non-zero on ‘PJSIP/204-00000351’
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] app_stack.c: PJSIP/204-00000351 Internal Gosub(crm-hangup,s,1) start
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Executing [s@crm-hangup:1] NoOp(“PJSIP/204-00000351”, “Sending Hangup to CRM”) in new stack
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Executing [s@crm-hangup:2] NoOp(“PJSIP/204-00000351”, “HANGUP CAUSE: 16”) in new stack
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Executing [s@crm-hangup:3] ExecIf(“PJSIP/204-00000351”, “0?Set(__CRM_VOICEMAIL=)”) in new stack
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Executing [s@crm-hangup:4] NoOp(“PJSIP/204-00000351”, “MASTER CHANNEL: 1591091472.1485 = 1591091472.1485”) in new stack
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Executing [s@crm-hangup:5] GotoIf(“PJSIP/204-00000351”, “0?return”) in new stack
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Executing [s@crm-hangup:6] Set(“PJSIP/204-00000351”, “__CRM_HANGUP=1”) in new stack
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] pbx.c: Executing [s@crm-hangup:7] AGI(“PJSIP/204-00000351”, “sangomacrm.agi”) in new stack
[2020-06-02 11:21:27] VERBOSE[61100][C-00000268] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
[2020-06-02 11:21:28] VERBOSE[61100][C-00000268] res_agi.c: <PJSIP/204-00000351>AGI Script sangomacrm.agi completed, returning 0
[2020-06-02 11:21:28] VERBOSE[61100][C-00000268] pbx.c: Executing [s@crm-hangup:8] Return(“PJSIP/204-00000351”, “”) in new stack
[2020-06-02 11:21:28] VERBOSE[61100][C-00000268] app_stack.c: Spawn extension (from-internal, h, 1) exited non-zero on ‘PJSIP/204-00000351’
[2020-06-02 11:21:28] VERBOSE[61100][C-00000268] app_stack.c: PJSIP/204-00000351 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=


(Itzik) #8

You can grep a full log by following the instructions here https://wiki.freepbx.org/display/SUP/Providing+Great+Debug#ProvidingGreatDebug-AsteriskLogs-PartII

Can you explain how these calls are placed on hold? I don’t see any music on hold starting or stopping in this log.

What it seems to me, that the extension disconnected the call. You might want to check the phone as well if it has any hold limitations.

And in case you are not aware of, parking works wonderfully.


(United Kingdom) #9

Thank you - I have now had clarification and it isn’t when the call is just on hold - we conducted a test and it disconnects after 30 minutes even if the call is ‘active’. We just spent 30 minutes on the phone call - actively talking and at exactly 30 minutes duration (1814 seconds to be exact!), the call cuts off and the dial tone plays the continuous ‘dead’ tone.

I will try to get the logs you have requested - I have the call identifications for the call we tested with this morning so will come back to you. Thank you for your help!


(Dave Burgess) #10

Search the forum (top right magnifying glass) for “30 minutes” and you’ll see many people have this problem. It’s usually a router configuration problem.


(United Kingdom) #11

For the purpose of keeping everything together - I contacted Gamma and they have come back with the following :slight_smile:

Hi Shelley,

I had a look at the call at 11:57 from 01233620040 to 01233647963 and I believe I have found the issue.

When the call is setup, the invite you send specifies that the Timer function is supported which is fine. When the destination answers with a 200OK SDP which requires a timer. Normal behaviour with SIP timers requires an exchange of “Invite SDP” and “200OK SDP” packets to refresh the timers that make up the call. The call progresses quite happily until a “BYE” from the destination, which I assume is due to the lack of update/ session refresh timers.

Can you contact your PBX maintainer and ask them to look over the settings and see if they can get the signalling to include refreshers?

I have attached a pcap for review.

Kind regards,


(Dave Burgess) #12

There are two approaches and the choice is yours. Both of these are common misconfigurations, so there are plenty of people in the forum that have solved this problem.

  1. You can turn off timers by setting the session timer to “0” (IIRC, double check with your search)
  2. You can fix the firewall router and the NAT settings in your outbound SIP connection to make sure that the traffic from your ITSP is getting back to the actual PBX.

Honestly, my opinion is that the second one is “more correct”, because not having timers can lead to calls where one end quits the call and the other end doesn’t know for half an hour. Either solution, though, is workable. The “right” solution (IMHO) is to do 1 (to get ops working) and then fix 2 (to avoid the problem in the future).


(United Kingdom) #13

Thank you so much! The problem is now resolved using Option 1 and Option 2 will be implemented once I can get my head around what I need to do!!


(system) closed #14

This topic was automatically closed 31 days after the last reply. New replies are no longer allowed.