<html>
  <head>
    <meta content="text/html; charset=windows-1252"
      http-equiv="Content-Type">
  </head>
  <body bgcolor="#FFFFFF" text="#000000">
    On 21-11-16 17:20, Matthew Jordan wrote:<br>
    <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>
    <tt><br>
    </tt><tt>Hello</tt><tt><br>
    </tt><tt> </tt><tt> </tt><tt><br>
    </tt><tt> </tt><tt> </tt><tt><br>
    </tt><tt> </tt><tt> 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.</tt><tt><br>
    </tt><tt> </tt><tt> </tt><tt><br>
    </tt><tt> </tt><tt> Now my dialplan just hangs at the Queue
      application :</tt><tt><br>
    </tt><tt> </tt><tt> </tt><tt><br>
    </tt><tt> </tt><tt> [Nov 22 13:52:16]     -- Executing
      [queue@pbx-routing:15] Queue("SIP/incoming-0000001c",
      "myqueue1,,,,30,,,") in new stack</tt><tt><br>
    </tt><tt> </tt><tt> [Nov 22 13:52:16]     -- Started music on hold,
      class 'default', on channel 'SIP/incoming-0000001c'</tt><tt><br>
    </tt><tt> </tt><tt> </tt><tt><br>
    </tt><tt> </tt><tt> (nothing happens further, we just sit 30
      seconds inside the queue)</tt><tt><br>
    </tt><tt> </tt><tt> </tt><tt><br>
    </tt><tt> </tt><tt> </tt><tt><br>
    </tt><tt> </tt><tt> I've generated debug output :</tt><tt><br>
    </tt><tt> </tt><tt> </tt><tt><br>
    </tt><tt> </tt><tt> ...</tt><tt><br>
    </tt><tt> </tt><tt> [Nov 22 13:52:27] DEBUG[27577][C-00000007]
      audiohook.c: Write factory 0x11b56e8 was pretty quick last time,
      waiting for them.</tt><tt><br>
    </tt><tt> </tt><tt> [Nov 22 13:52:27] DEBUG[27577][C-00000007]
      audiohook.c: Write factory 0x11b56e8 was pretty quick last time,
      waiting for them.</tt><tt><br>
    </tt><tt> </tt><tt> [Nov 22 13:52:27] DEBUG[27577][C-00000007]
      audiohook.c: Write factory 0x11b56e8 was pretty quick last time,
      waiting for them.</tt><tt><br>
    </tt><tt> </tt><tt> [Nov 22 13:52:27] DEBUG[27577][C-00000007]
      audiohook.c: Write factory 0x11b56e8 was pretty quick last time,
      waiting for them.</tt><tt><br>
    </tt><tt> </tt><tt> [Nov 22 13:52:27] DEBUG[27577][C-00000007]
      audiohook.c: Write factory 0x11b56e8 was pretty quick last time,
      waiting for them.</tt><tt><br>
    </tt><tt> </tt><tt> [Nov 22 13:52:27] DEBUG[27577][C-00000007]
      audiohook.c: Write factory 0x11b56e8 was pretty quick last time,
      waiting for them.</tt><tt><br>
    </tt><tt> </tt><tt> [Nov 22 13:52:27] DEBUG[27577][C-00000007]
      audiohook.c: Write factory 0x11b56e8 was pretty quick last time,
      waiting for them.</tt><tt><br>
    </tt><tt> </tt><tt> [Nov 22 13:52:27] DEBUG[27577][C-00000007]
      audiohook.c: Write factory 0x11b56e8 was pretty quick last time,
      waiting for them.</tt><tt><br>
    </tt><tt> </tt><tt> [Nov 22 13:52:27] DEBUG[27577][C-00000007]
      audiohook.c: Write factory 0x11b56e8 was pretty quick last time,
      waiting for them.</tt><tt><br>
    </tt><tt> </tt><tt> [Nov 22 13:52:27] DEBUG[27577][C-00000007]
      audiohook.c: Write factory 0x11b56e8 was pretty quick last time,
      waiting for them.</tt><tt><br>
    </tt><tt> </tt><tt> [Nov 22 13:52:27] DEBUG[27563][C-00000007]
      app_queue.c: There is 1 available member.</tt><tt><br>
    </tt><tt> </tt><tt> [Nov 22 13:52:27] DEBUG[27563][C-00000007]
      app_queue.c: It's our turn (SIP/incoming-0000001c).</tt><tt><br>
    </tt><tt> </tt><tt> [Nov 22 13:52:27] DEBUG[27563][C-00000007]
      app_queue.c: SIP/incoming-0000001c is trying to call a queue
      member.</tt><tt><br>
    </tt><tt> </tt><tt> [Nov 22 13:52:27] DEBUG[27563][C-00000007]
      app_queue.c: (Parallel) Trying 'Local/mysip467@CallFromQueue' with
      metric 0</tt><tt><br>
    </tt><tt> </tt><tt> [Nov 22 13:52:27] DEBUG[27563][C-00000007]
      app_queue.c: Local/mysip467@CallFromQueue has another call trying,
      can't receive call</tt><tt><br>
    </tt><tt> </tt><tt> [Nov 22 13:52:27] DEBUG[27563][C-00000007]
      app_queue.c: (Parallel) Trying 'Local/mysip517@CallFromQueue' with
      metric 0</tt><tt><br>
    </tt><tt> </tt><tt> [Nov 22 13:52:27] DEBUG[27563][C-00000007]
      app_queue.c: Local/mysip517@CallFromQueue has another call trying,
      can't receive call</tt><tt><br>
    </tt><tt> </tt><tt> [Nov 22 13:52:27] DEBUG[27563][C-00000007]
      app_queue.c: (Parallel) Trying 'Local/mysip440@CallFromQueue' with
      metric 0</tt><tt><br>
    </tt><tt> </tt><tt> [Nov 22 13:52:27] DEBUG[27563][C-00000007]
      app_queue.c: Local/mysip440@CallFromQueue has another call trying,
      can't receive call</tt><tt><br>
    </tt><tt> </tt><tt> [Nov 22 13:52:27] DEBUG[27563][C-00000007]
      app_queue.c: Nobody left to try ringing in queue</tt><tt><br>
    </tt><tt> </tt><tt> [Nov 22 13:52:27] DEBUG[27563][C-00000007]
      app_queue.c: Everyone is busy at this time</tt><tt><br>
    </tt><tt> </tt><tt> [Nov 22 13:52:27] DEBUG[27563][C-00000007]
      res_config_mysql.c: MySQL RealTime: Connection okay.</tt><tt><br>
    </tt><tt> </tt><tt> [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</tt><tt><br>
    </tt><tt> </tt><tt> [Nov 22 13:52:27] DEBUG[27577][C-00000007]
      audiohook.c: Write factory 0x11b56e8 was pretty quick last time,
      waiting for them.</tt><tt><br>
    </tt><tt> </tt><tt> [Nov 22 13:52:27] DEBUG[27577][C-00000007]
      audiohook.c: Write factory 0x11b56e8 was pretty quick last time,
      waiting for them.</tt><tt><br>
    </tt><tt> </tt><tt> [Nov 22 13:52:27] DEBUG[27577][C-00000007]
      audiohook.c: Write factory 0x11b56e8 was pretty quick last time,
      waiting for them.</tt><tt><br>
    </tt><tt> </tt><tt> [Nov 22 13:52:27] DEBUG[27577][C-00000007]
      audiohook.c: Write factory 0x11b56e8 was pretty quick last time,
      waiting for them.</tt><tt><br>
    </tt><tt> </tt><tt> ...</tt><tt><br>
    </tt><tt> </tt><tt> </tt><tt><br>
    </tt><tt> </tt><tt> </tt><tt><br>
    </tt><tt> </tt><tt> </tt><tt><br>
    </tt><tt> </tt><tt> </tt><tt>Should a file a bug report on the
      tracker ??</tt><tt><br>
    </tt><tt> </tt><tt><br>
    </tt><tt> </tt><tt><br>
    </tt><tt> </tt><tt> Kind regards</tt><tt><br>
    </tt><tt> </tt><tt> </tt><tt><br>
    </tt><tt> </tt><tt> </tt><tt><br>
    </tt><tt> </tt><tt> J.</tt><tt><br>
    </tt><tt> </tt><tt> </tt><br>
  </body>
</html>