I have been struggling with an issue for about 2 weeks now, I tried allot of settings buts until now I still don’t know what is wrong.
When 2 users call each other and a third user (USER_3 in the logs) tries to call user 2 (USER_2 in the logs), he doesn’t immediately get the busy tone and the connection is not directly ended.
We are using SSL and what I seem to be able to read from the logs is that the RTP connection between USER_2 and USER_3 is destroyed immediately but the SIP channel isn’t destroyed immediately and delays up to around 10 seconds…
We had this running in the past without SSL and the busy tone was given within a second.
The long delay is from [2019-09-30 19:00:52] to [2019-09-30 19:01:02], I put some blocks in the logs with the word “INTERESTING”, where I thought that that could interesting.
And I also noted where I think the USER_2 disconnected and USER_3.
The key issue on this is why is it going into overlap dialling mode and getting a digit timeout after part of the from_user context has been executed? I looked at this from the Asterisk side, and it looks to me to be FreePBX dialplan related.
-- Executing [USER_2@from-sip:1] Gosub("SIP/USER_3-00000023", "chexec,1(USER_2)")
-- Executing [chexec@from-sip:1] Set("SIP/USER_3-00000023", "TMOUT=60")
-- Executing [chexec@from-sip:2] Dial("SIP/USER_3-00000023", "SIP/USER_2")
-- Executing [chexec@from-sip:3] Wait("SIP/USER_3-00000023", "1") ==> NO USE
-- Executing [chexec@from-sip:4] Set("SIP/USER_3-00000023", "TMOUT=59")
-- Executing [chexec@from-sip:5] ExecIf("SIP/USER_3-00000023", "0?Return()")
[2019-09-30 19:01:02] WARNING[892][C-00000019]: pbx.c:4547 __ast_pbx_run: Timeout, but no rule 't' or 'e' in context 'from-sip'
Note that I’ve assumed that the dialplan execution lines are running on thread 892, from surrounding context, but I don’t think the verbosity was high enough to get a good trace.
I think the issue with the debugging might be that you are screen scraping, rather than using a log file, and as a result, you aren’t getting the headers on the VERBOSE messages which would tell you the time of the event and the thread number. All events associated with a channel running in the dialplan have the same thread number, which makes it easier to see which messages are relevant.
As it says there it is behaving as though, in the from-user context, after the Gosub, there are priorities that match the current extension as a prefix. I haven’t checked to see if Asterisk will actually revert to overlap dialling in that case, or not, in that case, but I don’t know of any other reason for a digit timeout on SIP.
For example (and it is only speculation that Asterisk will interpret it this way), I’m wondering if you have something like:
With default settings, please make a failing test call and post the regular Asterisk log (Reports -> Asterisk Logfiles). We no longer need the SIP trace (USER_2 is returning 486 as expected). We may eventually need the DEBUG level but just looking at the problematic dialplan may solve it.
You may need to also post some of the dialplan, because most readers here, including myself, are on FreePBX 14 or older where the from-sip context doesn’t even exist.
Also, you have a somewhat unusual case with both call waiting and voicemail disabled. Many younger people have never even heard a busy tone.
Please paste the redacted log at https://pastebin.freepbx.org/ and post the link here. You can also use pastebin.com or similar, but be aware that if you use Google Drive or any other service that requires the reader to log in and be tracked, some of the most helpful wizards on this forum will ignore your post.
First, just post the log (Reports → Asterisk Logfiles) of a problematic call. If it’s not clear what a particular context is trying to do, you can view the code, usually in
/etc/asterisk/extensions_additional.conf
If it’s not there, it is likely in one of the other files in /etc/asterisk .
I assume there has been some redaction of strings like USER_3_Ab. If so could you explain which parts are redactions and what the general syntax of an unredacted name is. Are there "_"s present in the actual names.
Although I’m only looking at this from a pure Asterisk point of view, the structure of the dialled numbers (extensions in Asterisk, but not FreePBX, terminology) is probably at the root of this problem.
The log does confirm that the digit timeout is on trying to execute the dialplan step after the Return and therefore presumably from-user,???, 2.
If I remember correctly, "_"s are ignored during pattern matching, so might cause some confusion if the dialplan uses pattern matching, assuming they are present in the unredacted data.
Sorry, but I can’t help further with this issue, because I’ve not yet tried FreePBX 15 nor Asterisk Realtime and it appears that your issue is related to specific details of both.
I hope that other members will review your log and chime in.
The problem is solved, I will post my solution here for anybody else in the future.
So after checking the extensions.conf file on this server I saw a huge amount of dialplans that were default installed by FreePBX.
When I compared the content of this file with the extensions.conf from the old server that worked and didn’t have FreePBX installed, I saw that that file was almost empty.
I copied the content of that file and pasted it in extensions_override_freepbx.conf, did a “dialplan reload” and now I get the busy tone immediately (2 seconds).
