[Home]

Summary:ASTERISK-29045: app_queue: Does not assign the first call in queue when one or more members are not in the range of MIN and MAX penalty
Reporter:Mario Lenis (mario.lenis)Labels:
Date Opened:2020-08-26 14:26:11Date Closed:
Priority:MinorRegression?No
Status:Open/NewComponents:Applications/app_queue
Versions:16.8.0 Frequency of
Occurrence		Constant
Related
Issues:
Environment:Centos7 x86_64 Intel(R) Xeon(R) Platinum 8175M CPU @ 2.50GHz RAM: 1Gb Attachments:( 0) debug_log_00001
( 1) logger_0001
Description:The first call in queue is not being assigned if one of the members has a penalty value out of the range. This is the setup

{{extensions.conf}}
{quote}
exten => 999,1,Noop()
same => n,Set(QUEUE_MIN_PENALTY=0)
same => n,Set(QUEUE_MAX_PENALTY=99999)
same => n,Queue(QueueA,tT)
{quote}

{{queues.conf}}
{quote}
[general]
persistentmembers = yes
negative_penalty_invalid = yes
shared_lastcall = yes
autofill = yes

[QueueA]
timeout = 16
strategy =rrmemory
servicelevel = 60
weight = 0
ringinuse = no
maxlen = 0
setinterfacevar = yes
setqueueentryvar = yes
setqueuevar = yes

member => Local/1001@agent,-1,,Agent:1001,no
member => Local/1002@agent,,,Agent:1002,no
{quote}

Status of the queue
{quote}
*CLI> queue show
QueueA has 0 calls (max unlimited) in 'rrmemory' strategy (12s holdtime, 11s talktime), W:0, C:6, A:0, SL:100.0%, SL2:100.0% within 60s
  Members:
     Local/1001@agent with penalty -1 (ringinuse disabled) (Not in use) has taken no calls yet
     Local/1002@agent (ringinuse disabled) (Not in use) has taken 6 calls (last was 325 secs ago)
  No Callers
{quote}

Then 3 calls enter to the queue, the first call is correctly assigned to the available agent.

{quote}
*CLI> queue show
QueueA has 2 calls (max unlimited) in 'rrmemory' strategy (9s holdtime, 11s talktime), W:0, C:6, A:0, SL:100.0%, SL2:100.0% within 60s
  Members:
     Local/1001@agent with penalty -1 (ringinuse disabled) (Not in use) has taken no calls yet
     Local/1002@agent (ringinuse disabled) (in call) (In use) has taken 6 calls (last was 705 secs ago)
  Callers:
     1. Local/ivr999@funciones-generales-000000e8;2 (wait: 0:09, prio: 0)
     2. Local/ivr999@funciones-generales-000000e9;2 (wait: 0:05, prio: 0)

*CLI> agent show all
Agent-ID Name                 State       Channel                        Talking with
1001                          NOT_INUSE   SIP/101-00000009              
1002                          INUSE       SIP/102-00000006               Local/1002@agent-000000e7;2
{quote}

Then the call attended by agent 1002 ends up, the next call should be {{Local/ivr999@funciones-generales-000000e8;2}}, instead, the call assigned to the agent is {{Local/ivr999@funciones-generales-000000e9;2}}

{quote}
*CLI> queue show
QueueA has 1 calls (max unlimited) in 'rrmemory' strategy (38s holdtime, 41s talktime), W:0, C:7, A:0, SL:100.0%, SL2:100.0% within 60s
  Members:
     Local/1001@agent with penalty -1 (ringinuse disabled) (Not in use) has taken no calls yet
     Local/1002@agent (ringinuse disabled) (in call) (In use) has taken 7 calls (last was 73 secs ago)
  Callers:
     1. Local/ivr999@funciones-generales-000000e8;2 (wait: 3:23, prio: 0)
{quote}

I have reproduced the situation many times and always happens, the problem is that if more calls enter to the queue, the 1st call in the queue order would not be assigned at least until it's the only one awaiting or in worst case scenario would no be assigned at all since more an more calls may enter to the queue.
Comments:By: Asterisk Team (asteriskteam) 2020-08-26 14:26:12.698-0500

Thanks for creating a report! The issue has entered the triage process. That means the issue will wait in this status until a Bug Marshal has an opportunity to review the issue. Once the issue has been reviewed you will receive comments regarding the next steps towards resolution. Please note that log messages and other files should not be sent to the Sangoma Asterisk Team unless explicitly asked for. All files should be placed on this issue in a sanitized fashion as needed.

A good first step is for you to review the [Asterisk Issue Guidelines|https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines] if you haven't already. The guidelines detail what is expected from an Asterisk issue report.

Then, if you are submitting a patch, please review the [Patch Contribution Process|https://wiki.asterisk.org/wiki/display/AST/Patch+Contribution+Process].

Please note that once your issue enters an open state it has been accepted. As Asterisk is an open source project there is no guarantee or timeframe on when your issue will be looked into. If you need expedient resolution you will need to find and pay a suitable developer. Asking for an update on your issue will not yield any progress on it and will not result in a response. All updates are posted to the issue when they occur.
By: Joshua C. Colp (jcolp) 2020-08-26 15:01:15.512-0500

So this requires a member to have a penalty of -1, and the negative_penalty_invalid option enabled?
By: Mario Lenis (mario.lenis) 2020-08-26 15:11:02.766-0500

Yes, in [general] it is set {{negative_penalty_invalid = yes}} and I have tested with -1 and above the range. Ex: 100000 when QUEUE_MAX_PENALTY=99999
By: Joshua C. Colp (jcolp) 2020-08-27 07:49:04.527-0500

Can you please attach a debug log (ensuring debug goes to a file in logger.conf and setting debug to level 5 using core set debug 5) of this? The app_queue module has debug messages which state why it is generally doing what it is doing.
By: Mario Lenis (mario.lenis) 2020-08-27 08:33:22.624-0500

Sure!, I filtered the output file to show {{app_queue.c}} information only, should I attach the full log?
By: Joshua C. Colp (jcolp) 2020-08-28 04:23:59.409-0500

A full log is always good to have just in case, otherwise it can be a continued back and forth.

As well within this log what is the channel that should have gotten an agent but did not?
By: Mario Lenis (mario.lenis) 2020-08-28 09:26:34.327-0500

You're right, I attached the full now. The channel that were supoused to be connected : Local/ivr999@funciones-generales-00000021;2

Channel attended: Local/ivr999@funciones-generales-0000001f;2
Queue, position 1. Local/ivr999@funciones-generales-00000021;2
Queue, position 2. Local/ivr999@funciones-generales-00000022;2

-------

I was trying to debug this situation last night and I found something :
Calls were added to the queue correctly:

{quote}
app_queue.c: Queue 'QueueA' Join, Channel 'Local/ivr999@funciones-generales-00000021;2', Position '1
app_queue.c: There is 1 available member.
app_queue.c: Queue 'QueueA' Join, Channel 'Local/ivr999@funciones-generales-00000022;2', Position '2'
app_queue.c: There is 1 available member.
{quote}

But in both cases the agent it was referring as available was the one with penalty out of the range, and I found that the app_queue tried to connect the call with the "available" agent many times

{quote}
app_queue.c: There is 1 available member.
app_queue.c: It's not our turn (Local/ivr999@funciones-generales-00000022;2).
app_queue.c: Queue QueueA has no realtime members defined. No need for update
app_queue.c: There is 1 available member.
app_queue.c: It's our turn (Local/ivr999@funciones-generales-00000021;2).
app_queue.c: Local/ivr999@funciones-generales-00000021;2 is trying to call a queue member.
app_queue.c: Trying 'Local/1002@agent' with metric 1
app_queue.c: Local/1002@agent not available, can't receive call
{quote}

>>>>>> Then, the agent gets available <<<<<<<<
{quote}
app_queue.c: Detected hangup of queue caller channel Local/ivr999@funciones-generales-0000001f;2
app_queue.c: Device 'Local/ivr999@funciones-generales' changed to state '2' (In use) but we don't care because they're not a member of any queue.
app_queue.c: Removed Local/1002@agent from pending_members
{quote}

Then I see what might be the reason the 1st call in row is not being connected:

{{app_queue.c: There are 2 available members.}}

And since in the queues.conf file I have autofill = yes, the calls are connected in parallel.
By: Joshua C. Colp (jcolp) 2020-09-01 05:04:27.109-0500

So if you disable autofill the behavior works as expected? That returns things to a serialized predictable ordering.
By: Mario Lenis (mario.lenis) 2020-09-02 18:23:27.319-0500

Hi, Joshua, thanks in advance for being interested on this, I do appreciate it since you must have tons of work.

That's right, I just did the test and it worked, one curious thing is that the time to assign the call to the next available agent was "notable", wasn't instant as usual, it took like a second o two to assign the call.
By: Benjamin Keith Ford (bford) 2020-09-03 10:54:44.356-0500

Thanks for the info, [~mario.lenis]. I think we have enough to go off of to open up an issue now.