Questions on the queue_log

Asterisk Asterisk Support
1

i didn’t want to open a bug on this until i had queried the community…

we are in inbound call center, and make extensive use of the queue features of asterisk.

currently, when a queue call is transferred by an agent, app_queue logs the extension the call was transferred to, as well as the context. however, it does not log the calltime or holdtime, as it does with COMPLETECALLER and COMPLETEAGENT. there is a patch out there to add these the holdtime and calltime to the log entry, but they are added after the transfer-extension and context.

if possible, i’d like to propose that the holdtime and calltime are put BEFORE the extension and context, for the sole purpose of maintaining a consistent format for the queue_log entries…that way, for all of the successful calls, the holdtime, calltime, and extension (if it’s a transfer) are always in the same order - this will allow users like me to be able to dump the data into a database and actually do something with it. the current TRANSFER disposition is kind of useless in that regard.

this is just my opinion, and i may be way off base, but it seems to me like we’d want this sort of consistency as these applications mature more and more.

discuss.

2

Morning bro !

Are you sure ??

See the log line from my 1.2.7.1 version (i think it changed…):

1146737154|1146737132.2500|acdstadt_tag|SIP/46-c085|CONNECT|22
1146737155|1146737132.2500|acdstadt_tag|SIP/46-c085|COMPLETEAGENT|22|1

Easy to see:
Unix timestamp !
If you declare a MySql field as “Unix Timestamp”, the conversion for (eg) a webinterface would be done by the engine automatically.

3

i’m not talking about changing COMPLETECALLER or COMPLETEAGENT, i’m talking about changing TRANSFER.

check your logs again - they do NOT store TRANSFER information in the same order.

in your two lines, the CONNECT displays the holdtime (22 sec), and the COMPLETEAGENT displays the holdtime (again, 22 sec) and the calltime (1 sec).

however, if you had a TRANSFER in there, it would look like this (pulled directly from one of our logs)

so, even though this was a completed call, we don’t get the holdtime or calltime, which is screwing up our statistics - we don’t know with any accuracy the average call time and average hold time for our agents (something that is important, as we have service metrics that we attempt to meet). what i am proposing is that we do away with the context for the transfer, and insert the holdtime and talktime, so the line would look like this:

this shows that 2040 received a call that was holding for 22 seconds, they talked for 125 seconds, and it was then transferred to 2008.

that would be perfect. in fact, i’ll probably go ahead and make a patch anyway, but won’t submit it unless someone shows interest - for our systems, this is the way we need to log things. the only other viable option would be to set each ‘column’ in the log file to have a specific value, like the CDR records (in other words, the seventh column would always be the holdtime, the eight column would always be the talktime, the 12th column would always be the transferred extension…)

that’s my $0.02, anyways, i’d like to hear more thoughts on this, should there be any.

4

Ah ok, i see.

5

Did anyone found a solution for this?
Or was it deployed as a bug?

thank you,

Diogo Serra

6

try this ( i haven’t tested it yet, just came up with it…)

in an unmodified app_queue.c for asterisk 1.2.7.1, find line 2276

the line looks like this:

change to this:

ast_queue_log(queuename, qe->chan->uniqueid, peer->name, "TRANSFER", "%ld|%ld|%s", (long)(callstart - qe->start), (long)(time(NULL) - callstart), qe->chan->exten);

all i’ve done is rearranged the call to ast_queue_log to put the starttime, the endtime, and the extension in place of the extension and context, as per my post above.

this should work fine…i’m going to play with it a bit on my test box, let me know if you have any problems.

also, diogo, since you use queues, do you have any problems with multiple calls being delivered to agents? if you have a few seconds, would you mind looking at bug 6315? the patch seems to have lost it’s effectiveness in 1.2.4, and i need to try and find out why…

EDIT: fixed a typo

7

patch:

[code]— app_queue.c 2006-04-04 11:59:18.000000000 -0500
+++ app_queue_new.c 2006-05-30 09:26:15.000000000 -0500
@@ -2273,7 +2273,7 @@
bridge = ast_bridge_call(qe->chan,peer, &bridge_config);

            if (strcasecmp(oldcontext, qe->chan->context) || strcasecmp(oldexten, qe->chan->exten)) {

  •                   ast_queue_log(queuename, qe->chan->uniqueid, peer->name, "TRANSFER", "%s|%s", qe->chan->exten, qe->chan->context);

  •                   ast_queue_log(queuename, qe->chan->uniqueid, peer->name, "TRANSFER", "%ld|%ld|%s", (long)(callstart - qe->start), (long)(time(NULL) - callstart), qe->chan->exten);
          } else if (qe->chan->_softhangup) {
                  ast_queue_log(queuename, qe->chan->uniqueid, peer->name, "COMPLETECALLER", "%ld|%ld",
                                (long)(callstart - qe->start), (long)(time(NULL) - callstart));[/code]
8

yup, that worked - here is an excerpt from my queue_log file after applying the patch on my test server.

[code]1149013420|1149013420.18|TestQueue|NONE|ENTERQUEUE||102

EDIT: now that you guys got me started, i’ve been fixing some other
1149013422|1149013420.18|TestQueue|SIP/102-a7bc|CONNECT|2
1149013448|1149013420.18|TestQueue|SIP/102-a7bc|TRANSFER|2|26|8000
[/code]

i’ll probably roll this change out to one server tonight, and the rest later this week…feel free to do whatever you want with my changed code…it’s not like i did a lot of work on it.

EDIT: you guys got me started on this, and now i’ve gone through and fixed a few other problems in the app_queue logging system. the COMPLETECALLER and COMPLETEAGENT statuses are supposed to log the original position of the caller in the log file, but don’t. here is how to fix that:

change lines 2278 and 2292 to reflect the changes in bold

original line format:
ast_queue_log(queuename, qe->chan->uniqueid, peer->name, “COMPLETEXXXXX”, “%ld|%ld”, (long)(callstart - qe->start), (long)(time(NULL) - callstart));

with changes:
ast_queue_log(queuename, qe->chan->uniqueid, peer->name, “COMPLETEXXXXX”, “%ld|%ld|%d”, (long)(callstart - qe->start), (long)(time(NULL) - callstart), qe->opos);

now, for those of you still reading, this begs another question - we only have three ‘extra’ fields of data, past the event. adding the original caller position uses up all three for COMPLETECALLER and COMPLETEAGENT, but TRANSFER, which is in effect a COMPLETEAGENT, is already using all three, so you cannot store the original position without adding a fourth ‘extra’ column. this shouldn’t be a big deal, actually, but we could just ditch the extension that the agent transferred the caller to and put the original position there instead…does that make sense?

i ask only because i use the original position, along with waittimes, to graphically show the load so that managers can try to staff for the heaviest call periods.

in any case, i might modify the transfer entry to look like this:

this would log the original position as well as the extension the call was transferred to, but logging to mysql (as i do) would require adding a fourth ‘arg’ column…again, not a biggie, but something to keep in mind.

i’m open to your thoughts guys, and sorry to clutter the thread up so much, but we handle several thousand inbound calls a day via the queues, and NOT being able to accurately determine what is happening is not an option. PLEASE give me some feedback if you have any.[/b]