<html>
<head>
<meta content="text/html; charset=windows-1252"
http-equiv="Content-Type">
</head>
<body bgcolor="#FFFFFF" text="#000000">
On 21-11-16 19:14, Jonas Kellens wrote:<br>
<blockquote cite="mid:5833399A.4000600@telenet.be" type="cite">
<meta content="text/html; charset=windows-1252"
http-equiv="Content-Type">
<br>
<div class="moz-cite-prefix">On 21-11-16 17:20, Matthew Jordan
wrote:<br>
</div>
<blockquote
cite="mid:CAN2PU+6Qtw-FhU9AMuRfPkO6YYDNeTjt0XqXisPZTtWiQzvUxw@mail.gmail.com"
type="cite">
<div dir="ltr"><br>
<div class="gmail_extra"><br>
<div class="gmail_quote">On Mon, Nov 21, 2016 at 10:05 AM,
Jonas Kellens <span dir="ltr"><<a
moz-do-not-send="true"
href="mailto:jonas.kellens@telenet.be" target="_blank">jonas.kellens@telenet.be</a>></span>
wrote:<br>
<blockquote class="gmail_quote" style="margin:0px 0px 0px
0.8ex;border-left:1px solid
rgb(204,204,204);padding-left:1ex">
<div bgcolor="#FFFFFF"><span class="gmail-"> On 21-11-16
15:17, Matthew Jordan wrote:<br>
<blockquote type="cite">
<div dir="ltr">
<div class="gmail_extra"><br>
<div class="gmail_quote">On Mon, Nov 21, 2016
at 7:05 AM, Jonas Kellens <span dir="ltr"><<a
moz-do-not-send="true"
href="mailto:jonas.kellens@telenet.be"
target="_blank">jonas.kellens@telenet.be</a>></span>
wrote:<br>
<blockquote class="gmail_quote"
style="margin:0px 0px 0px
0.8ex;border-left:1px solid
rgb(204,204,204);padding-left:1ex">
<div bgcolor="#FFFFFF"> <font
face="Helvetica, Arial, sans-serif">Hello<br>
<br>
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.<br>
<br>
Example 1 :<br>
<br>
[Nov 21 08:17:57] pbx.c: Executing
[queue@pbx-routing:15]
Queue("SIP/incoming-00000246",
"myqueue1,,,,300,,,") in new stack<br>
[Nov 21 08:17:57] res_musiconhold.c:
Started music on hold, class
'default', on channel
'SIP/incoming-00000246'<br>
<br>
[Nov 21 08:18:26] pbx.c: Executing
[mysip692@CallFromQueue:1]
NoOp("Local/mysip692@CallFromQ<wbr>ueue-0000003c;2",
"") in new stack<br>
[Nov 21 08:18:26] app_queue.c: Called
Local/mysip692@CallFromQueue<br>
[Nov 21 08:18:26] pbx.c: Executing
[mysip692@CallFromQueue:3]
Dial("Local/mysip692@CallFromQ<wbr>ueue-0000003c;2",
"SIP/mysip692") in new stack<br>
[Nov 21 08:18:26] app_dial.c: Called
SIP/mysip692<br>
<br>
<br>
Example 2 :<br>
<br>
[Nov 21 08:20:11] pbx.c: Executing
[queue@pbx-routing:15]
Queue("SIP/incoming-00000255",
"myqueue1,,,,300,,,") in new stack<br>
[Nov 21 08:20:11] res_musiconhold.c:
Started music on hold, class
'default', on channel
'SIP/incoming-00000255'<br>
<br>
[Nov 21 08:20:45] app_queue.c: Called
Local/mysip692@CallFromQueue<br>
[Nov 21 08:20:45] pbx.c: Executing
[mysip692@CallFromQueue:1]
NoOp("Local/mysip692@CallFromQ<wbr>ueue-00000040;2",
"") in new stack<br>
[Nov 21 08:20:45] pbx.c: Executing
[mysip692@CallFromQueue:3]
Dial("Local/mysip692@CallFromQ<wbr>ueue-00000040;2",
"SIP/mysip692") in new stack<br>
[Nov 21 08:20:45] app_dial.c: Called
SIP/mysip692<br>
<br>
<br>
I did not see this behaviour in
previous Asterisk versions.<br>
<br>
Could this be a bug ?<br>
<br>
</font></div>
</blockquote>
<div><br>
</div>
<div>There's not enough information here to
know what is preventing the call from
occurring.</div>
<div><br>
</div>
<div>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. </div>
</div>
<div><br>
</div>
-- <br>
<div
class="gmail-m_-2721457819232755237gmail_signature">Matthew
Jordan<br>
</div>
</div>
</div>
</blockquote>
<br>
<br>
</span> Hello<br>
<br>
<br>
and what exactly am I looking for in the debug logs ?<br>
<br>
I have generated debug output and re-produced the
issue.<br>
<br>
<br>
Again 23 seconds before calling the queue member :<br>
<br>
[Nov 21 16:23:33] pbx.c: Executing
[queue@pbx-routing:15] Queue("SIP/incoming-00004e6e",
"myqueue1,,,,300,,,") in new stack<br>
[Nov 21 16:23:33] res_musiconhold.c: Started music on
hold, class 'default', on channel
'SIP/incoming-00004e6e'<br>
<br>
[Nov 21 16:23:56] pbx.c: Executing
[mysip692@CallFromQueue:1] NoOp("Local/mysip692@<wbr>CallFromQueue-0000081a;2",
"") in new stack<br>
[Nov 21 16:23:56] app_queue.c: Called
Local/mysip692@CallFromQueue<br>
[Nov 21 16:23:56] pbx.c: Executing
[mysip692@CallFromQueue:2] NoOp("Local/mysip692@<wbr>CallFromQueue-0000081a;2",
"exten = mysip692") in new stack<br>
[Nov 21 16:23:56] pbx.c: Executing
[mysip692@CallFromQueue:3] Dial("Local/mysip692@<wbr>CallFromQueue-0000081a;2",
"SIP/mysip692") in new stack<br>
[Nov 21 16:23:56] app_dial.c: Called SIP/mysip692<br>
[Nov 21 16:23:56] app_dial.c: SIP/mysip692-00004e86 is
ringing<br>
[Nov 21 16:23:56] app_queue.c:
Local/mysip692@CallFromQueue-<wbr>0000081a;1 is
ringing<br>
<br>
<br>
<br>
Could it be that it is because my Queue member
'mysip692' is occupied in another bridge (call) ?<br>
<br>
This I see in the logs just before the Call Queue
starts calling the queue member :<br>
<br>
[Nov 21 16:23:55] bridge_native_rtp.c: Locally RTP
bridged 'SIP/mysip-00004e6a' and
'SIP/incoming-00004e63' in stack<br>
[Nov 21 16:23:55] bridge_channel.c: Channel
SIP/incoming-00004e63 left 'native_rtp' basic-bridge
<fed056d3-669a-493d-a4bd-<wbr>f0d9ab0102a7><br>
[Nov 21 16:23:55] bridge_channel.c: Channel
SIP/mysip-00004e6a left 'native_rtp' basic-bridge
<fed056d3-669a-493d-a4bd-<wbr>f0d9ab0102a7><br>
<br>
<br>
A bit too coincidal, no ?<br>
<br>
So then it has something to do with the bridging ?<br>
<br>
<br>
<br>
I did not have this behaviour in previous Asterisk
versions.<br>
<br>
</div>
</blockquote>
<div><br>
</div>
<div>Those aren't debug logs. Instructions for generating
debug information can be found on the wiki:</div>
<div><br>
</div>
<div><a moz-do-not-send="true"
href="https://wiki.asterisk.org/wiki/display/AST/Collecting+Debug+Information">https://wiki.asterisk.org/wiki/display/AST/Collecting+Debug+Information</a></div>
<div><br>
</div>
<div>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.</div>
</div>
<div><br>
</div>
-- <br>
<div class="gmail_signature">Matthew Jordan<br>
</div>
</div>
</div>
</blockquote>
<br>
Hello<br>
<br>
indeed no debug log output. Therefore I need to know what to
filter because there is a lot of information written.<br>
<br>
"you have not configured the Queue to ring the Queue Member while
they are busy"<br>
<br>
--> where would I configure this ?<br>
<br>
I have in my realtime MySQL tables 'queues' a column 'ringinuse'
with value 'no'.<br>
<br>
<br>
I would expect that the call does enter the call queue but when
the member is called there is a 'busy' notification for that
member. This way the dialplan can continue with the next step.<br>
<br>
Now the call 'hangs' at the queue application until this queue()
command can continue.<br>
<br>
Is this normal behaviour in version 13.12.2 ? Personally I prefer
the previous behaviour of the Queue application.<br>
<br>
<br>
<br>
Kind regards.<br>
<br>
J.<br>
</blockquote>
<br>
I have more info concerning this bug. It seems that once a member of
the queue can not be reached due to the fact that it is busy in
another call, this queue member is never again being called by the
queue application !<br>
<br>
Look at these 3 calls :<br>
<br>
<br>
Call 1 : both queue members are being called (normal behaviour,
everything is fine)<br>
<br>
<br>
[Nov 22 11:27:10] VERBOSE[1992][C-00000898] pbx.c: Executing
[queue@pbx-routing:15] Queue("SIP/incoming-0000219f",
"myqueue1,,,,10,,,") in new stack<br>
[Nov 22 11:27:10] VERBOSE[1992][C-00000898] res_musiconhold.c:
Started music on hold, class 'default', on channel
'SIP/incoming-0000219f'<br>
<br>
[Nov 22 11:27:10] VERBOSE[2063][C-00000898] pbx.c: Executing
[mysip517@CallFromQueue:1]
NoOp("Local/mysip517@CallFromQueue-00000447;2", "") in new stack<br>
[Nov 22 11:27:10] VERBOSE[1992][C-00000898] app_queue.c: Called
Local/mysip517@CallFromQueue<br>
[Nov 22 11:27:10] VERBOSE[2063][C-00000898] pbx.c: Executing
[mysip517@CallFromQueue:2]
NoOp("Local/mysip517@CallFromQueue-00000447;2", "exten = mysip517")
in new stack<br>
[Nov 22 11:27:10] VERBOSE[2063][C-00000898] pbx.c: Executing
[mysip517@CallFromQueue:3]
Dial("Local/mysip517@CallFromQueue-00000447;2", "SIP/mysip517") in
new stack<br>
<br>
[Nov 22 11:27:10] VERBOSE[2064][C-00000898] pbx.c: Executing
[mysip467@CallFromQueue:1]
NoOp("Local/mysip467@CallFromQueue-00000448;2", "") in new stack<br>
[Nov 22 11:27:10] VERBOSE[1992][C-00000898] app_queue.c: Called
Local/mysip467@CallFromQueue<br>
[Nov 22 11:27:10] VERBOSE[2064][C-00000898] pbx.c: Executing
[mysip467@CallFromQueue:2]
NoOp("Local/mysip467@CallFromQueue-00000448;2", "exten = mysip467")
in new stack<br>
[Nov 22 11:27:10] VERBOSE[2064][C-00000898] pbx.c: Executing
[mysip467@CallFromQueue:3]
Dial("Local/mysip467@CallFromQueue-00000448;2", "SIP/mysip467") in
new stack<br>
<br>
[Nov 22 11:27:10] VERBOSE[2063][C-00000898] app_dial.c: Called
SIP/mysip517<br>
[Nov 22 11:27:10] VERBOSE[2064][C-00000898] app_dial.c: Called
SIP/mysip467<br>
[Nov 22 11:27:10] VERBOSE[2063][C-00000898] app_dial.c:
SIP/mysip517-000021a1 is ringing<br>
[Nov 22 11:27:10] VERBOSE[1992][C-00000898] app_queue.c:
Local/mysip517@CallFromQueue-00000447;1 is ringing<br>
[Nov 22 11:27:11] VERBOSE[2064][C-00000898] app_dial.c:
SIP/mysip467-000021a2 is ringing<br>
[Nov 22 11:27:11] VERBOSE[1992][C-00000898] app_queue.c:
Local/mysip467@CallFromQueue-00000448;1 is ringing<br>
<br>
<br>
***************************************************************************************************************************************************<br>
<br>
<br>
Call 2 : only one member is being called, queue member mysip467 is
busy in another conversation (still normal behaviour, everything is
fine)<br>
<br>
[Nov 22 11:33:05] VERBOSE[6703][C-000008e0] pbx.c: Executing
[queue@pbx-routing:15] Queue("SIP/incoming-000022bc",
"myqueue1,,,,10,,,") in new stack<br>
[Nov 22 11:33:05] VERBOSE[6703][C-000008e0] res_musiconhold.c:
Started music on hold, class 'default', on channel
'SIP/incoming-000022bc'<br>
<br>
[Nov 22 11:33:05] VERBOSE[6751][C-000008e0] pbx.c: Executing
[mysip517@CallFromQueue:1]
NoOp("Local/mysip517@CallFromQueue-0000046c;2", "") in new stack<br>
[Nov 22 11:33:05] VERBOSE[6703][C-000008e0] app_queue.c: Called
Local/mysip517@CallFromQueue<br>
[Nov 22 11:33:05] VERBOSE[6751][C-000008e0] pbx.c: Executing
[mysip517@CallFromQueue:2]
NoOp("Local/mysip517@CallFromQueue-0000046c;2", "exten = mysip517")
in new stack<br>
[Nov 22 11:33:05] VERBOSE[6751][C-000008e0] pbx.c: Executing
[mysip517@CallFromQueue:3]
Dial("Local/mysip517@CallFromQueue-0000046c;2", "SIP/mysip517") in
new stack<br>
<br>
[Nov 22 11:33:05] VERBOSE[6752][C-000008e0] pbx.c: Executing
[mysip467@CallFromQueue:1]
NoOp("Local/mysip467@CallFromQueue-0000046d;2", "") in new stack<br>
[Nov 22 11:33:05] VERBOSE[6703][C-000008e0] app_queue.c: Called
Local/mysip467@CallFromQueue<br>
[Nov 22 11:33:05] VERBOSE[6752][C-000008e0] pbx.c: Executing
[mysip467@CallFromQueue:2]
NoOp("Local/mysip467@CallFromQueue-0000046d;2", "exten = mysip467")
in new stack<br>
[Nov 22 11:33:05] VERBOSE[6752][C-000008e0] pbx.c: Executing
[mysip467@CallFromQueue:3]
Dial("Local/mysip467@CallFromQueue-0000046d;2", "SIP/mysip467") in
new stack<br>
<br>
[Nov 22 11:33:05] VERBOSE[6751][C-000008e0] app_dial.c: Called
SIP/mysip517<br>
[Nov 22 11:33:05] VERBOSE[6752][C-000008e0] app_dial.c: Called
SIP/mysip467<br>
[Nov 22 11:33:05] VERBOSE[6751][C-000008e0] app_dial.c:
SIP/mysip517-000022be is ringing<br>
[Nov 22 11:33:05] VERBOSE[6703][C-000008e0] app_queue.c:
Local/mysip517@CallFromQueue-0000046c;1 is ringing<br>
<br>
[Nov 22 11:33:05] VERBOSE[6752][C-000008e0] app_dial.c:
SIP/mysip467-000022bf redirecting info has changed, passing it to
Local/mysip467@CallFromQueue-0000046d;2<br>
[Nov 22 11:33:05] VERBOSE[6752][C-000008e0] app_dial.c:
SIP/mysip467-000022bf is busy<br>
[Nov 22 11:33:05] VERBOSE[6752][C-000008e0] app_dial.c: Everyone is
busy/congested at this time (1:1/0/0)<br>
[Nov 22 11:33:05] VERBOSE[6752][C-000008e0] pbx.c: Executing
[mysip467@CallFromQueue:4]
Hangup("Local/mysip467@CallFromQueue-0000046d;2", "") in new stack<br>
[Nov 22 11:33:05] VERBOSE[6752][C-000008e0] pbx.c: Spawn extension
(CallFromQueue, mysip467, 4) exited non-zero on
'Local/mysip467@CallFromQueue-0000046d;2'<br>
<br>
***************************************************************************************************************************************************<br>
<br>
<br>
Call 3 : only one member is being called, queue member mysip467 is
no longer in another conversation thus should also be called again
(not normal behaviour)<br>
<br>
<br>
[Nov 22 11:33:30] VERBOSE[7081][C-000008e7] pbx.c: Executing
[queue@pbx-routing:15] Queue("SIP/incoming-000022d6",
"myqueue1,,,,10,,,") in new stack<br>
[Nov 22 11:33:30] VERBOSE[7081][C-000008e7] res_musiconhold.c:
Started music on hold, class 'default', on channel
'SIP/incoming-000022d6'<br>
<br>
[Nov 22 11:33:30] VERBOSE[7129][C-000008e7] pbx.c: Executing
[mysip517@CallFromQueue:1]
NoOp("Local/mysip517@CallFromQueue-00000472;2", "") in new stack<br>
[Nov 22 11:33:30] VERBOSE[7081][C-000008e7] app_queue.c: Called
Local/mysip517@CallFromQueue<br>
[Nov 22 11:33:30] VERBOSE[7129][C-000008e7] pbx.c: Executing
[mysip517@CallFromQueue:2]
NoOp("Local/mysip517@CallFromQueue-00000472;2", "exten = mysip517")
in new stack<br>
[Nov 22 11:33:30] VERBOSE[7129][C-000008e7] pbx.c: Executing
[mysip517@CallFromQueue:3]
Dial("Local/mysip517@CallFromQueue-00000472;2", "SIP/mysip517") in
new stack<br>
[Nov 22 11:33:30] VERBOSE[7129][C-000008e7] app_dial.c: Called
SIP/mysip517<br>
[Nov 22 11:33:30] VERBOSE[7129][C-000008e7] app_dial.c:
SIP/mysip517-000022d8 is ringing<br>
[Nov 22 11:33:30] VERBOSE[7081][C-000008e7] app_queue.c:
Local/mysip517@CallFromQueue-00000472;1 is ringing<br>
<br>
(only mysip517 is being called)<br>
<br>
***************************************************************************************************************************************************<br>
<br>
<br>
If a queue member (in my example mysip467) states to the Queue
application that it is busy and can not take a call, it seems that
the Queue application remembers this forever and never again sends a
call to this queue member. Even if the member is available again.<br>
<br>
<br>
Should a file a bug report on the tracker ??<br>
<br>
<br>
<br>
<br>
Kind regards.<br>
<br>
<br>
J.<br>
</body>
</html>