Busy tone received with delay of around 10 seconds


(Expire) #1

Dear FreePBX Community,

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.

Here you will find the logs here:
https://drive.google.com/file/d/1ZGywKGR8YKrUUmxTxbxsHACd0zLVrutf/view?usp=sharing

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.

Best regards,
x


(David55) #2

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.


(Expire) #3

Dear David,

Thank you for your reply.
Could you please guide me to how I can better troubleshoot or solve the FreePBX issue?

Also please let me know what kind of debug you need to help me further so I can provide it to you.

I already need this solved as we have been struggling with this for weeks :frowning:

Thank you,
Abder


(David55) #4

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.

Please note I’m not a FreePBX user, I was just following this through from https://community.asterisk.org/t/busy-tone-received-with-delay/81090/2

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:

Exten => _12.,1,…
Exten => _12.,n, Gosub(…
Exten => _1234,n,…

given an extension of 123, might start a digit timeout on the third line.

I redirected you to FreePBX as the from_user context is populated by FreePBX.


#5

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.


(Expire) #6

Dear Stewart,

I’m actually new to FreePBX, could you tell me where I can find the dialplan to post it here?
Tried searching in the GUI, but nothing seemed to popup…

Thank you,
Best regards,
X.


#7

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 .


(Expire) #8

Dear Stewart,

Thanks for helping out, you will find the logs for same issue here:
https://pastebin.freepbx.org/view/7bef4115

USER_1 calls USER_2, and then USER_3 tries to call USER_2, after 11 seconds USER_3 gets the message that USER_2 is in another call.

Here are the call details as well…
https://pastebin.freepbx.org/view/d53fb404

Thank you.

Best regards,
X.


(David55) #9

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.


(Expire) #10

Dear David,

No the users do not include _'s, it exists of 3 letters, followed by 3 number, then again 3 letters. Example: ABC123DEF

And the users that I put here are:
USER_1_Ta
USER_2_Ja
USER_3_Ab

So you can replace the 3 usernames above with anything more clear to you, but to confirm the username is 3 letters, 3 numbers, 3 letters, so no “_”.

Best regards,
X.


#11

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.


(David55) #12

As a workaround, you could try reducing the digit timeout. I don’t know how to do this on FreePBX. You may be relying on this elsewhere.


(Expire) #13

Dear all,

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).

Thank you all for your help!

Best regards,
X.


(Lorne Gaetz) #14

While I’m sure your complaint is gone, that “solution” is completely incorrect and inappropriate. I’ve removed the solution flag from this post.


(David55) #15

I think there is some ambiguity as to which dialplan code the OP moved. The code generated by FreePBX must not be moved.