[asterisk-users] Asterisk 13.12.2 : strange queue behaviour
Jonas Kellens
jonas.kellens at telenet.be
Tue Nov 22 07:59:02 CST 2016
On 21-11-16 17:20, Matthew Jordan wrote:
>
>
> On Mon, Nov 21, 2016 at 10:05 AM, Jonas Kellens
> <jonas.kellens at telenet.be <mailto:jonas.kellens at telenet.be>> wrote:
>
> On 21-11-16 15:17, Matthew Jordan wrote:
>>
>> On Mon, Nov 21, 2016 at 7:05 AM, Jonas Kellens
>> <jonas.kellens at telenet.be <mailto:jonas.kellens at telenet.be>> wrote:
>>
>> Hello
>>
>> when using Asterisk version 13.12.2 I notice that it takes up
>> to 30 seconds (sometimes even longer) for a call queue to
>> call its members.
>>
>> Example 1 :
>>
>> [Nov 21 08:17:57] pbx.c: Executing [queue at pbx-routing:15]
>> Queue("SIP/incoming-00000246", "myqueue1,,,,300,,,") in new stack
>> [Nov 21 08:17:57] res_musiconhold.c: Started music on hold,
>> class 'default', on channel 'SIP/incoming-00000246'
>>
>> [Nov 21 08:18:26] pbx.c: Executing [mysip692 at CallFromQueue:1]
>> NoOp("Local/mysip692 at CallFromQueue-0000003c;2", "") in new stack
>> [Nov 21 08:18:26] app_queue.c: Called
>> Local/mysip692 at CallFromQueue
>> [Nov 21 08:18:26] pbx.c: Executing [mysip692 at CallFromQueue:3]
>> Dial("Local/mysip692 at CallFromQueue-0000003c;2",
>> "SIP/mysip692") in new stack
>> [Nov 21 08:18:26] app_dial.c: Called SIP/mysip692
>>
>>
>> Example 2 :
>>
>> [Nov 21 08:20:11] pbx.c: Executing [queue at pbx-routing:15]
>> Queue("SIP/incoming-00000255", "myqueue1,,,,300,,,") in new stack
>> [Nov 21 08:20:11] res_musiconhold.c: Started music on hold,
>> class 'default', on channel 'SIP/incoming-00000255'
>>
>> [Nov 21 08:20:45] app_queue.c: Called
>> Local/mysip692 at CallFromQueue
>> [Nov 21 08:20:45] pbx.c: Executing [mysip692 at CallFromQueue:1]
>> NoOp("Local/mysip692 at CallFromQueue-00000040;2", "") in new stack
>> [Nov 21 08:20:45] pbx.c: Executing [mysip692 at CallFromQueue:3]
>> Dial("Local/mysip692 at CallFromQueue-00000040;2",
>> "SIP/mysip692") in new stack
>> [Nov 21 08:20:45] app_dial.c: Called SIP/mysip692
>>
>>
>> I did not see this behaviour in previous Asterisk versions.
>>
>> Could this be a bug ?
>>
>>
>> There's not enough information here to know what is preventing
>> the call from occurring.
>>
>> I'd look at a debug log between the caller entering the Queue and
>> the outbound call being made. That should illustrate what is
>> causing the delay.
>>
>> --
>> Matthew Jordan
>
>
> Hello
>
>
> and what exactly am I looking for in the debug logs ?
>
> I have generated debug output and re-produced the issue.
>
>
> Again 23 seconds before calling the queue member :
>
> [Nov 21 16:23:33] pbx.c: Executing [queue at pbx-routing:15]
> Queue("SIP/incoming-00004e6e", "myqueue1,,,,300,,,") in new stack
> [Nov 21 16:23:33] res_musiconhold.c: Started music on hold, class
> 'default', on channel 'SIP/incoming-00004e6e'
>
> [Nov 21 16:23:56] pbx.c: Executing [mysip692 at CallFromQueue:1]
> NoOp("Local/mysip692 at CallFromQueue-0000081a;2", "") in new stack
> [Nov 21 16:23:56] app_queue.c: Called Local/mysip692 at CallFromQueue
> [Nov 21 16:23:56] pbx.c: Executing [mysip692 at CallFromQueue:2]
> NoOp("Local/mysip692 at CallFromQueue-0000081a;2", "exten =
> mysip692") in new stack
> [Nov 21 16:23:56] pbx.c: Executing [mysip692 at CallFromQueue:3]
> Dial("Local/mysip692 at CallFromQueue-0000081a;2", "SIP/mysip692") in
> new stack
> [Nov 21 16:23:56] app_dial.c: Called SIP/mysip692
> [Nov 21 16:23:56] app_dial.c: SIP/mysip692-00004e86 is ringing
> [Nov 21 16:23:56] app_queue.c:
> Local/mysip692 at CallFromQueue-0000081a;1 is ringing
>
>
>
> Could it be that it is because my Queue member 'mysip692' is
> occupied in another bridge (call) ?
>
> This I see in the logs just before the Call Queue starts calling
> the queue member :
>
> [Nov 21 16:23:55] bridge_native_rtp.c: Locally RTP bridged
> 'SIP/mysip-00004e6a' and 'SIP/incoming-00004e63' in stack
> [Nov 21 16:23:55] bridge_channel.c: Channel SIP/incoming-00004e63
> left 'native_rtp' basic-bridge <fed056d3-669a-493d-a4bd-f0d9ab0102a7>
> [Nov 21 16:23:55] bridge_channel.c: Channel SIP/mysip-00004e6a
> left 'native_rtp' basic-bridge <fed056d3-669a-493d-a4bd-f0d9ab0102a7>
>
>
> A bit too coincidal, no ?
>
> So then it has something to do with the bridging ?
>
>
>
> I did not have this behaviour in previous Asterisk versions.
>
>
> Those aren't debug logs. Instructions for generating debug information
> can be found on the wiki:
>
> https://wiki.asterisk.org/wiki/display/AST/Collecting+Debug+Information
>
> That being said, if the Queue Member is currently busy (which will be
> denoted by their device state), and you have not configured the Queue
> to ring the Queue Member while they are busy, then I would expect any
> new caller to hang out in the Queue until that Member is available.
>
> --
> Matthew Jordan
Hello
I did a call with my queue member mysip517 and now this one is also no
longer being called by the Queue application. So I can reproduce this
bug every time again and again.
Now my dialplan just hangs at the Queue application :
[Nov 22 13:52:16] -- Executing [queue at pbx-routing:15]
Queue("SIP/incoming-0000001c", "myqueue1,,,,30,,,") in new stack
[Nov 22 13:52:16] -- Started music on hold, class 'default', on
channel 'SIP/incoming-0000001c'
(nothing happens further, we just sit 30 seconds inside the queue)
I've generated debug output :
...
[Nov 22 13:52:27] DEBUG[27577][C-00000007] audiohook.c: Write factory
0x11b56e8 was pretty quick last time, waiting for them.
[Nov 22 13:52:27] DEBUG[27577][C-00000007] audiohook.c: Write factory
0x11b56e8 was pretty quick last time, waiting for them.
[Nov 22 13:52:27] DEBUG[27577][C-00000007] audiohook.c: Write factory
0x11b56e8 was pretty quick last time, waiting for them.
[Nov 22 13:52:27] DEBUG[27577][C-00000007] audiohook.c: Write factory
0x11b56e8 was pretty quick last time, waiting for them.
[Nov 22 13:52:27] DEBUG[27577][C-00000007] audiohook.c: Write factory
0x11b56e8 was pretty quick last time, waiting for them.
[Nov 22 13:52:27] DEBUG[27577][C-00000007] audiohook.c: Write factory
0x11b56e8 was pretty quick last time, waiting for them.
[Nov 22 13:52:27] DEBUG[27577][C-00000007] audiohook.c: Write factory
0x11b56e8 was pretty quick last time, waiting for them.
[Nov 22 13:52:27] DEBUG[27577][C-00000007] audiohook.c: Write factory
0x11b56e8 was pretty quick last time, waiting for them.
[Nov 22 13:52:27] DEBUG[27577][C-00000007] audiohook.c: Write factory
0x11b56e8 was pretty quick last time, waiting for them.
[Nov 22 13:52:27] DEBUG[27577][C-00000007] audiohook.c: Write factory
0x11b56e8 was pretty quick last time, waiting for them.
[Nov 22 13:52:27] DEBUG[27563][C-00000007] app_queue.c: There is 1
available member.
[Nov 22 13:52:27] DEBUG[27563][C-00000007] app_queue.c: It's our turn
(SIP/incoming-0000001c).
[Nov 22 13:52:27] DEBUG[27563][C-00000007] app_queue.c:
SIP/incoming-0000001c is trying to call a queue member.
[Nov 22 13:52:27] DEBUG[27563][C-00000007] app_queue.c: (Parallel)
Trying 'Local/mysip467 at CallFromQueue' with metric 0
[Nov 22 13:52:27] DEBUG[27563][C-00000007] app_queue.c:
Local/mysip467 at CallFromQueue has another call trying, can't receive call
[Nov 22 13:52:27] DEBUG[27563][C-00000007] app_queue.c: (Parallel)
Trying 'Local/mysip517 at CallFromQueue' with metric 0
[Nov 22 13:52:27] DEBUG[27563][C-00000007] app_queue.c:
Local/mysip517 at CallFromQueue has another call trying, can't receive call
[Nov 22 13:52:27] DEBUG[27563][C-00000007] app_queue.c: (Parallel)
Trying 'Local/mysip440 at CallFromQueue' with metric 0
[Nov 22 13:52:27] DEBUG[27563][C-00000007] app_queue.c:
Local/mysip440 at CallFromQueue has another call trying, can't receive call
[Nov 22 13:52:27] DEBUG[27563][C-00000007] app_queue.c: Nobody left to
try ringing in queue
[Nov 22 13:52:27] DEBUG[27563][C-00000007] app_queue.c: Everyone is busy
at this time
[Nov 22 13:52:27] DEBUG[27563][C-00000007] res_config_mysql.c: MySQL
RealTime: Connection okay.
[Nov 22 13:52:27] DEBUG[27563][C-00000007] res_config_mysql.c: MySQL
RealTime: Retrieve SQL: SELECT * FROM queue_members WHERE interface LIKE
'%' AND queue_name = 'myqueue1' ORDER BY interface
[Nov 22 13:52:27] DEBUG[27577][C-00000007] audiohook.c: Write factory
0x11b56e8 was pretty quick last time, waiting for them.
[Nov 22 13:52:27] DEBUG[27577][C-00000007] audiohook.c: Write factory
0x11b56e8 was pretty quick last time, waiting for them.
[Nov 22 13:52:27] DEBUG[27577][C-00000007] audiohook.c: Write factory
0x11b56e8 was pretty quick last time, waiting for them.
[Nov 22 13:52:27] DEBUG[27577][C-00000007] audiohook.c: Write factory
0x11b56e8 was pretty quick last time, waiting for them.
...
Should a file a bug report on the tracker ??
Kind regards
J.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.digium.com/pipermail/asterisk-users/attachments/20161122/46e7eea5/attachment.html>
More information about the asterisk-users
mailing list