[Home]

Summary:ASTERISK-15373: Queue with wrapuptime "call" agent that shouldn't have any call
Reporter:Magnus Benngard (benngard2)Labels:
Date Opened:2009-12-28 09:16:21.000-0600Date Closed:2010-05-05 11:04:04
Priority:MinorRegression?No
Status:Closed/CompleteComponents:Applications/app_queue
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) putty.log
Description:I did some tests on Asterisk SVN-trunk-r234256.

extensions.conf
exten => 0317998989,1,ExecIf($[${DB_EXISTS(CFIM/0317998989)}]?Goto(${DB(CFIM/0317998989)},1)
exten => 0317998989,2,ExecIf($[${QUEUE_MEMBER(0317998989,logged)}=0]?Dial(H323/900@Avaya))
exten => 0317998989,3,Answer()
exten => 0317998989,4,Queue(0317998989,rt)
exten => 0317998989,5,Hangup()
exten => 989,1,Goto(0317998989,1) <- just for lazy people in our company

queues.conf
[general]
autofill=yes
keepstats=yes
[0317998989]
retry=5
strategy=rrmemory
timeout=20
wrapuptime=120

agents.conf
[general]
persistentagents=yes
[agents]
agent => 0317998971,1234,Stefan Andersson
agent => 0317998972,1234,Kerem Tubluk
agent => 0317998975,1234,Magnus Benngard
agent => 0317998976,1234,Jimmy Beckman

Logging in agents through a manager script, sample output from cli:
sip*CLI> queue show 0317998989
0317998989   has 0 calls (max unlimited) in 'rrmemory' strategy (17s holdtime, 59s talktime), W:0, C:7, A:2, SL:0.0% within 0s
  Members:
     SIP/0317998975 with penalty 2 (dynamic) (Not in use) has taken no calls yet
     SIP/0317998976 with penalty 1 (dynamic) (Not in use) has taken 7 calls (last was 2564 secs ago)
  No Callers
If I call the queue, 0317998976 will ofc get the call but when we hang up and I call within 120 seconds, 0317998976 will still get the call.

Shouldn't that second call go to 0317998975?
Comments:By: Leif Madsen (lmadsen) 2010-01-04 12:56:30.000-0600

Could you provide console output with debug logging enabled ('debug' in logger.conf) and 'core set verbose 10', 'core set debug 10' enabled? Then attach the output of that to this issue. Thanks!
By: Magnus Benngard (benngard2) 2010-01-05 02:12:02.000-0600

0317998971 logged in queue with penalty 2
0317998976 logged in queue with penalty 1
0317998975 calls 989, exten => 989,1,Goto(0317998989,1)
both calls are answered by 0317998976

sip*CLI>
 == Using UDPTL CoS mark 5
   -- Executing [989@inputinterior.se:1] Goto("SIP/0317998975-000000a6", "0317998989,1") in new stack
   -- Goto (inputinterior.se,0317998989,1)
   -- Executing [0317998989@inputinterior.se:1] ExecIf("SIP/0317998975-000000a6", "0?Goto(,1") in new stack
   -- Executing [0317998989@inputinterior.se:2] ExecIf("SIP/0317998975-000000a6", "0?Dial(OOH323/900@Avaya)") in new stack
   -- Executing [0317998989@inputinterior.se:3] Answer("SIP/0317998975-000000a6", "") in new stack
   -- Executing [0317998989@inputinterior.se:4] Queue("SIP/0317998975-000000a6", "0317998989,rt") in new stack
 == Using UDPTL CoS mark 5
   -- SIP/0317998976-000000a7 is ringing
   -- SIP/0317998976-000000a7 answered SIP/0317998975-000000a6
 == Spawn extension (inputinterior.se, 0317998989, 4) exited non-zero on 'SIP/0317998975-000000a6'
 == Using UDPTL CoS mark 5
   -- Executing [989@inputinterior.se:1] Goto("SIP/0317998975-000000a8", "0317998989,1") in new stack
   -- Goto (inputinterior.se,0317998989,1)
   -- Executing [0317998989@inputinterior.se:1] ExecIf("SIP/0317998975-000000a8", "0?Goto(,1") in new stack
   -- Executing [0317998989@inputinterior.se:2] ExecIf("SIP/0317998975-000000a8", "0?Dial(OOH323/900@Avaya)") in new stack
   -- Executing [0317998989@inputinterior.se:3] Answer("SIP/0317998975-000000a8", "") in new stack
   -- Executing [0317998989@inputinterior.se:4] Queue("SIP/0317998975-000000a8", "0317998989,rt") in new stack
 == Using UDPTL CoS mark 5
   -- SIP/0317998976-000000a9 is ringing
   -- SIP/0317998976-000000a9 answered SIP/0317998975-000000a8
 == Spawn extension (inputinterior.se, 0317998989, 4) exited non-zero on 'SIP/0317998975-000000a8'
sip*CLI>
By: Leif Madsen (lmadsen) 2010-01-05 08:41:41.000-0600

I don't see any debugging information, just the console information there. You need to enable debugging in logger.conf and then 'logger reload' from the CLI.

Also, it will be very chatty, so please attach as a plain text file to this issue.
By: Magnus Benngard (benngard2) 2010-01-05 10:45:39.000-0600

Did upload a "putty.log", 0317998985 calls the queue 2 times in a row.
0317998975 did receive both calls without any wrapup-time.
By: laszlovl (lvl) 2010-04-26 04:53:02

We also encountered issues with WRAPUPTIME suddenly not being respected anymore. Eventually, I've traced it down to the following: it breaks as soon as you do a 'queue reset stats', or a 'queue reload'. I believe this is due to the following function in app_queue.c:

static void clear_queue(struct call_queue *q)
{
q->holdtime = 0;
q->callscompleted = 0;
q->callsabandoned = 0;
q->callscompletedinsl = 0;
q->wrapuptime = 0;
q->talktime = 0;

if (q->members) {
struct member *mem;
struct ao2_iterator mem_iter = ao2_iterator_init(q->members, 0);
while ((mem = ao2_iterator_next(&mem_iter))) {
mem->calls = 0;
ao2_ref(mem, -1);
}
ao2_iterator_destroy(&mem_iter);
}
}

Because of the line "q->wrapuptime = 0", the wrapuptime for the queue is permanently set to 0 as soon as this function is called. I think the solution is to remove that line, and instead set mem->lastcall = 0 inside the member iterator.

I'm not too familiar with the asterisk sourcecode though, so I'll let someone with more experience submit a patch.
By: Leif Madsen (lmadsen) 2010-04-26 14:26:44

lvl: actually you could submit a patch for that small issue you saw and someone else could potentially test it to see if that resolves the issue -- sometimes the simple changes make a big impact! :)
By: Ben Winslow (rain) 2010-04-29 11:51:13

I encountered the problem with wrapuptime resetting as well, and have submitted bug ASTERISK-16030 with a patch to fix it.  I found this bug while searching for other reports of the same problem.  Your proposed fix is exactly what I implemented, lvl.
By: Magnus Benngard (benngard2) 2010-05-03 09:29:33

Did apply (manually) what lvl suggested to trunk version and it seems to do the trick.
By: Digium Subversion (svnbot) 2010-05-05 10:59:38

Repository: asterisk
Revision: 261233

_U  branches/1.6.2/
U   branches/1.6.2/apps/app_queue.c

------------------------------------------------------------------------
r261233 | pabelanger | 2010-05-05 10:59:38 -0500 (Wed, 05 May 2010) | 17 lines

Merged revisions 261232 via svnmerge from
https://origsvn.digium.com/svn/asterisk/trunk

........
 r261232 | pabelanger | 2010-05-05 11:42:07 -0400 (Wed, 05 May 2010) | 10 lines
 
 'queue reset stats' erroneously clears wrapuptime configuration.
 
 Resets each member's lastcall to 0 now.
 
 (closes issue ASTERISK-16030, ASTERISK-15373)
 Reported by: rain
 Patches:
       wrapuptime_reset_fix.diff uploaded by rain (license 327)
 Tested by: rain
........

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=261233