QM, ATTEMPTS patch and strange statistics

[Vide]

Hi

we have an Asterisk 1.2.24 installation with the ATTEMPTS patch to app_queue.c and a recompiled Asterisk, and in general it works.
Anyway, I have noted a very strange behaviour. Situation:
- queue with 4 agents, everyone is busy talking
- asterisk console reports this:

Local/707@from-internal/n (dynamic) (In use) has taken 1 calls (last was 191 secs ago)
Local/708@from-internal/n (dynamic) (In use) has taken 3 calls (last was 330 secs ago)
Local/705@from-internal/n (dynamic) (In use) has taken 4 calls (last was 282 secs ago)
Local/704@from-internal/n (dynamic) (In use) has taken 17 calls (last was 138 secs ago)


so these are 4 SIP channels and Asterisk know that the 4 are busy.
- I have the

ringinuse = no

option in the appropriate queue in queues.conf but nonetheless ATTEMPTS are appended to the queue_log! This is the really annoying, that makes ATTEMPTS statistics completely useless in my QM installation: if all agents are busy, as said, and a new call enter the queue, an ATTEMPT is recorded for EVERY agent, every N seconds where N is the "retry" value in queues.conf.
This doesn't have to work like this, agents are busy because they are talking, not because they are rejecting calls/not answering. Anyone experiencing something similiar?
Is my configuration wrong somehow? or is this considered "normal"? I repeat: asterisk correctly detect if th sip channel is in use or if it isn't.

[QueueMetrics]

I have a feeling this is not normal - whiuch queue strategy are you running?

[Vide]

In this very queue, rrmemory, but it happens with fewestcalls as well.

[QueueMetrics]

I am not sure why this happens, likely the patch went in the wrong place.... would you care to post a sample call with all the attempts logged?

[Vide]

This is where tha patch was applied in apps/app_queue.c

1574         if (res) {
   1575                 /* Again, keep going even if there's an error */
   1576                 if (option_debug)
   1577                         ast_log(LOG_DEBUG, "ast call on peer returned %d\n", res);
   1578                 if (option_verbose > 2)
   1579                         ast_verbose(VERBOSE_PREFIX_3 "Couldn't call %s\n", tmp->interface);
   1580                 ast_hangup(tmp->chan);
   1581                 tmp->chan = NULL;
   1582                 tmp->stillgoing = 0;
   1583                 (*busies)++;
   1584                 return 0;
   1585         } else {
   1586 if ( qe->parent->strategy != QUEUE_STRATEGY_RINGALL ) {
   1587 ast_queue_log(qe->parent->name, qe->chan->uniqueid, tmp->interface, "AGENTATTEMPT", "");
   1588 }
   1589
   1590                 if (qe->parent->eventwhencalled) {
   1591                         manager_event(EVENT_FLAG_AGENT, "AgentCalled",
   1592                                                 "AgentCalled: %s\r\n"
   1593                                                 "ChannelCalling: %s\r\n"
   1594                                                 "CallerID: %s\r\n"
   1595                                                 "CallerIDName: %s\r\n"
   1596                                                 "Context: %s\r\n"
   1597                                                 "Extension: %s\r\n"
   1598                                                 "Priority: %d\r\n",
   1599                                                 tmp->interface, qe->chan->name,
   1600                                                 tmp->chan->cid.cid_num ? tmp->chan->cid.cid_num : "unknown",
   1601                                                 tmp->chan->cid.cid_name ? tmp->chan->cid.cid_name : "unknown",
   1602                                                 qe->chan->context, qe->chan->exten, qe->chan->priority);
   1603                 }


and this is an extract of queue_log

1193735323|1193735294.133081|7006|NONE|ENTERQUEUE||$CLIENT_CLID
1193735391|1193735294.133081|7006|Local/705@from-internal/n|AGENTATTEMPT|
1193735392|1193735294.133081|7006|Local/708@from-internal/n|AGENTATTEMPT|
1193735397|1193735294.133081|7006|Local/708@from-internal/n|AGENTATTEMPT|
1193735397|1193735294.133081|7006|Local/705@from-internal/n|AGENTATTEMPT|
1193735406|1193735294.133081|7006|Local/708@from-internal/n|AGENTATTEMPT|
1193735407|1193735294.133081|7006|Local/705@from-internal/n|AGENTATTEMPT|
1193735412|1193735294.133081|7006|Local/708@from-internal/n|AGENTATTEMPT|
1193735412|1193735294.133081|7006|Local/705@from-internal/n|AGENTATTEMPT|
1193735422|1193735294.133081|7006|Local/708@from-internal/n|AGENTATTEMPT|
1193735422|1193735294.133081|7006|Local/705@from-internal/n|AGENTATTEMPT|
1193735427|1193735294.133081|7006|Local/708@from-internal/n|AGENTATTEMPT|
1193735427|1193735294.133081|7006|Local/705@from-internal/n|AGENTATTEMPT|
1193735437|1193735294.133081|7006|Local/708@from-internal/n|AGENTATTEMPT|
1193735437|1193735294.133081|7006|Local/705@from-internal/n|AGENTATTEMPT|
1193735442|1193735294.133081|7006|Local/708@from-internal/n|AGENTATTEMPT|
1193735442|1193735294.133081|7006|Local/705@from-internal/n|AGENTATTEMPT|
1193735447|1193735294.133081|7006|NONE|EXITWITHTIMEOUT|1


705 and 708 where the only two agents logged in the queue 7006 and both of them were talking.

[QueueMetrics]

It looks correct - as you can see, it is generated exactly where Asterisk would generate its own event.
Looks like an Asterisk bug to me - maybe the exact version you're using ignores

Code: [Select]

ringinuse = no

[QueueMetrics]

Maybe here is the answer: http://www.asteriskguru.com/board/ringinuse-setting-in-queueconf-vt2306.html

[Vide]

Damn... so this is the normal 1.2 behaviour?? But this makes attempts logging just...useless because there will be always big numbers.
Anyway, any idea if this option could be backported to 1.2.x? or we should start thinking about a 1.4 upgrade?

[QueueMetrics]

I'd go for 1.4, or use Agent/xxx channels instead.

[Vide]

Please clarify the second option you gave me 

[QueueMetrics]

If you use logged-in agents (Agent/101...) through AgentCallbackLogin you will have correct statistics even without your option