[asterisk-bugs] [JIRA] (ASTERISK-29427) Queue in round robin is not ringing agents for the correct amount of time

Fri May 14 09:46:17 CDT 2021

    [ https://issues.asterisk.org/jira/browse/ASTERISK-29427?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=254895#comment-254895 ] 

Benjamin Keith Ford commented on ASTERISK-29427:
------------------------------------------------

I think the behavior here is correct according to the docs in queues.conf:
{code}
; If timeoutrestart is set to yes, then the timeout for an agent to answer is
; reset if a BUSY or CONGESTION is received.  This can be useful if agents
; are able to cancel a call with reject or similar.
{code}
However, the log message printed out is misleading once it reaches that final amount of time, reporting the overall duration and not the duration that it ringed the last time.

> Queue in round robin is not ringing agents for the correct amount of time
> -------------------------------------------------------------------------
>
>                 Key: ASTERISK-29427
>                 URL: https://issues.asterisk.org/jira/browse/ASTERISK-29427
>             Project: Asterisk
>          Issue Type: Bug
>      Security Level: None
>          Components: Applications/app_queue
>    Affects Versions: 16.17.0
>         Environment: CentOS 6 64bit
>            Reporter: Leandro Dardini
>            Assignee: Unassigned
>
> I have a queue realtime in round robin configuration, trying to ring a large number of agents. After few days of usage, the queue is starting to report wrong times for the ring time of agents, terminating to ring an agent before the configured timeout.
> Here is an example of the result of the calls and timeout.
> {noformat}
> # grep C-000057d7 /var/log/asterisk/full.0 | grep app_queue.c
> [2021-05-12 16:30:44] VERBOSE[28439][C-000057d7] app_queue.c: Called Local/AG-002-NFR-128708 at fromotherpbx/n
> [2021-05-12 16:31:05] VERBOSE[28439][C-000057d7] app_queue.c: Local/AG-002-NFR-128708 at fromotherpbx-00004c01;1 is busy
> [2021-05-12 16:31:05] VERBOSE[28439][C-000057d7] app_queue.c: Nobody picked up in 21000 ms
> [2021-05-12 16:31:05] VERBOSE[28439][C-000057d7] app_queue.c: Called Local/AG-006-NFR-128710 at fromotherpbx/n
> [2021-05-12 16:31:06] VERBOSE[28439][C-000057d7] app_queue.c: Local/AG-006-NFR-128710 at fromotherpbx-00004c02;1 is busy
> [2021-05-12 16:31:06] VERBOSE[28439][C-000057d7] app_queue.c: Nobody picked up in 1000 ms
> [2021-05-12 16:31:06] VERBOSE[28439][C-000057d7] app_queue.c: Called Local/AG-000-NFR-129142 at fromotherpbx/n
> [2021-05-12 16:31:07] VERBOSE[28439][C-000057d7] app_queue.c: Local/AG-000-NFR-129142 at fromotherpbx-00004c03;1 is ringing
> [2021-05-12 16:31:09] VERBOSE[28439][C-000057d7] app_queue.c: Nobody picked up in 25000 ms
> {noformat}
> _In this last attempt, the queue cancelled the call to the agent thinking 25 seconds are passed, but only 3 seconds are passed_
> {noformat}
> [2021-05-12 16:31:10] VERBOSE[28439][C-000057d7] app_queue.c: Called Local/AG-000-NFR-129142 at fromotherpbx/n
> [2021-05-12 16:31:12] VERBOSE[28439][C-000057d7] app_queue.c: Local/AG-000-NFR-129142 at fromotherpbx-00004c04;1 is ringing
> [2021-05-12 16:31:35] VERBOSE[28439][C-000057d7] app_queue.c: Nobody picked up in 25000 ms
> [2021-05-12 16:31:36] VERBOSE[28439][C-000057d7] app_queue.c: Called Local/AG-002-NFR-128708 at fromotherpbx/n
> [2021-05-12 16:31:57] VERBOSE[28439][C-000057d7] app_queue.c: Local/AG-002-NFR-128708 at fromotherpbx-00004c05;1 is busy
> [2021-05-12 16:31:57] VERBOSE[28439][C-000057d7] app_queue.c: Nobody picked up in 21000 ms
> [2021-05-12 16:31:57] VERBOSE[28439][C-000057d7] app_queue.c: Called Local/AG-006-NFR-128710 at fromotherpbx/n
> [2021-05-12 16:32:01] VERBOSE[28439][C-000057d7] app_queue.c: Nobody picked up in 25000 ms
> {noformat}
> _Again, after an agent refused a call, it seems the timer is not reset correctly and only the remaining time is used for the next agent_
> {noformat}
> [2021-05-12 16:32:02] VERBOSE[28439][C-000057d7] app_queue.c: Called Local/AG-000-NFR-129142 at fromotherpbx/n
> [2021-05-12 16:32:03] VERBOSE[28439][C-000057d7] app_queue.c: Local/AG-000-NFR-129142 at fromotherpbx-00004c07;1 is ringing
> [2021-05-12 16:32:27] VERBOSE[28439][C-000057d7] app_queue.c: Nobody picked up in 25000 ms
> [2021-05-12 16:32:28] VERBOSE[28439][C-000057d7] app_queue.c: Called Local/AG-002-NFR-128708 at fromotherpbx/n
> [2021-05-12 16:32:48] VERBOSE[28439][C-000057d7] app_queue.c: Local/AG-002-NFR-128708 at fromotherpbx-00004c08;1 is busy
> [2021-05-12 16:32:48] VERBOSE[28439][C-000057d7] app_queue.c: Nobody picked up in 20000 ms
> [2021-05-12 16:32:48] VERBOSE[28439][C-000057d7] app_queue.c: Called Local/AG-006-NFR-128710 at fromotherpbx/n
> [2021-05-12 16:32:53] VERBOSE[28439][C-000057d7] app_queue.c: Nobody picked up in 25000 ms
> {noformat}
> _Yes, it seems exactly the time not spent by the previous agent is used for the next agent, without resetting the agent timeout_
> {noformat}
> [2021-05-12 16:32:54] VERBOSE[28439][C-000057d7] app_queue.c: Called Local/AG-000-NFR-129142 at fromotherpbx/n
> [2021-05-12 16:32:54] VERBOSE[28439][C-000057d7] app_queue.c: Local/AG-000-NFR-129142 at fromotherpbx-00004c11;1 is ringing
> [2021-05-12 16:33:19] VERBOSE[28439][C-000057d7] app_queue.c: Nobody picked up in 25000 ms
> [2021-05-12 16:33:20] VERBOSE[28439][C-000057d7] app_queue.c: Called Local/AG-002-NFR-128708 at fromotherpbx/n
> [2021-05-12 16:33:41] VERBOSE[28439][C-000057d7] app_queue.c: Local/AG-002-NFR-128708 at fromotherpbx-00004c19;1 is busy
> [2021-05-12 16:33:41] VERBOSE[28439][C-000057d7] app_queue.c: Nobody picked up in 21000 ms
> [2021-05-12 16:33:41] VERBOSE[28439][C-000057d7] app_queue.c: Called Local/AG-006-NFR-128710 at fromotherpbx/n
> [2021-05-12 16:33:45] VERBOSE[28439][C-000057d7] app_queue.c: Nobody picked up in 25000 ms
> {noformat}
> _Another time, same issue_
> {noformat}
> [2021-05-12 16:33:46] VERBOSE[28439][C-000057d7] app_queue.c: Called Local/AG-000-NFR-129142 at fromotherpbx/n
> [2021-05-12 16:33:47] VERBOSE[28439][C-000057d7] app_queue.c: Local/AG-000-NFR-129142 at fromotherpbx-00004c1b;1 is ringing
> [2021-05-12 16:34:11] VERBOSE[28439][C-000057d7] app_queue.c: Nobody picked up in 25000 ms
> [2021-05-12 16:34:12] VERBOSE[28439][C-000057d7] app_queue.c: Called Local/AG-002-NFR-128708 at fromotherpbx/n
> [2021-05-12 16:34:33] VERBOSE[28439][C-000057d7] app_queue.c: Local/AG-002-NFR-128708 at fromotherpbx-00004c1c;1 is busy
> [2021-05-12 16:34:33] VERBOSE[28439][C-000057d7] app_queue.c: Nobody picked up in 21000 ms
> [2021-05-12 16:34:33] VERBOSE[28439][C-000057d7] app_queue.c: Called Local/AG-006-NFR-128710 at fromotherpbx/n
> [2021-05-12 16:34:37] VERBOSE[28439][C-000057d7] app_queue.c: Local/AG-006-NFR-128710 at fromotherpbx-00004c1d;1 is ringing
> [2021-05-12 16:34:37] VERBOSE[28439][C-000057d7] app_queue.c: Nobody picked up in 25000 ms
> [2021-05-12 16:34:38] VERBOSE[28439][C-000057d7] app_queue.c: Called Local/AG-000-NFR-129142 at fromotherpbx/n
> [2021-05-12 16:34:39] VERBOSE[28439][C-000057d7] app_queue.c: Local/AG-000-NFR-129142 at fromotherpbx-00004c1e;1 is ringing
> [2021-05-12 16:35:03] VERBOSE[28439][C-000057d7] app_queue.c: Nobody picked up in 25000 ms
> [2021-05-12 16:35:04] VERBOSE[28439][C-000057d7] app_queue.c: Called Local/AG-002-NFR-128708 at fromotherpbx/n
> [2021-05-12 16:35:24] VERBOSE[28439][C-000057d7] app_queue.c: Local/AG-002-NFR-128708 at fromotherpbx-00004c1f;1 is busy
> [2021-05-12 16:35:24] VERBOSE[28439][C-000057d7] app_queue.c: Nobody picked up in 20000 ms
> [2021-05-12 16:35:24] VERBOSE[28439][C-000057d7] app_queue.c: Called Local/AG-006-NFR-128710 at fromotherpbx/n
> [2021-05-12 16:35:29] VERBOSE[28439][C-000057d7] app_queue.c: Local/AG-006-NFR-128710 at fromotherpbx-00004c20;1 is ringing
> [2021-05-12 16:35:29] VERBOSE[28439][C-000057d7] app_queue.c: Nobody picked up in 25000 ms
> [2021-05-12 16:35:30] VERBOSE[28439][C-000057d7] app_queue.c: Called Local/AG-000-NFR-129142 at fromotherpbx/n
> [2021-05-12 16:35:31] VERBOSE[28439][C-000057d7] app_queue.c: Local/AG-000-NFR-129142 at fromotherpbx-00004c21;1 is ringing
> [2021-05-12 16:35:55] VERBOSE[28439][C-000057d7] app_queue.c: Nobody picked up in 25000 ms
> [2021-05-12 16:35:56] VERBOSE[28439][C-000057d7] app_queue.c: Called Local/AG-002-NFR-128708 at fromotherpbx/n
> [2021-05-12 16:36:17] VERBOSE[28439][C-000057d7] app_queue.c: Local/AG-002-NFR-128708 at fromotherpbx-00004c27;1 is busy
> [2021-05-12 16:36:17] VERBOSE[28439][C-000057d7] app_queue.c: Nobody picked up in 21000 ms
> [2021-05-12 16:36:17] VERBOSE[28439][C-000057d7] app_queue.c: Called Local/AG-006-NFR-128710 at fromotherpbx/n
> [2021-05-12 16:36:21] VERBOSE[28439][C-000057d7] app_queue.c: Local/AG-006-NFR-128710 at fromotherpbx-00004c28;1 is ringing
> [2021-05-12 16:36:21] VERBOSE[28439][C-000057d7] app_queue.c: Nobody picked up in 25000 ms
> [2021-05-12 16:36:22] VERBOSE[28439][C-000057d7] app_queue.c: Called Local/AG-000-NFR-129142 at fromotherpbx/n
> [2021-05-12 16:36:23] VERBOSE[28439][C-000057d7] app_queue.c: Local/AG-000-NFR-129142 at fromotherpbx-00004c29;1 is ringing
> [2021-05-12 16:36:44] VERBOSE[28439][C-000057d7] app_queue.c: Nobody picked up in 22000 ms
> {noformat}

--
This message was sent by Atlassian JIRA
(v6.2#6252)