This patch adds additional information to the EXITWITHKEY and EXITWITHTIMEOUT

entries in the queue log.
(issue #7561, reported and originally patched by fkasumovic, patch slightly
 modified and updated to trunk by me)


git-svn-id: https://origsvn.digium.com/svn/asterisk/trunk@62462 65c4cc65-6c06-0410-ace0-fbb531ad65f3

3 files changed, 34 insertions, 23 deletions

diff --git a/CHANGES b/CHANGES
index bf4eef3ce..162a04e5c 100644
--- a/CHANGES
+++ b/CHANGES
@@ -113,6 +113,8 @@ Queue changes
   * Added min-announce-frequency option to queues.conf which allows you to control the
      minimum amount of time between queue announcements for use when the caller's queue
      position changes frequently.
+  * Added additional information to EXITWITHTIMEOUT and EXITWITHKEY events in the
+     queue log.
 
 MeetMe Changes
 --------------
diff --git a/apps/app_queue.c b/apps/app_queue.c
index e6387afb0..0d72d9928 100644
--- a/apps/app_queue.c
+++ b/apps/app_queue.c
@@ -2056,7 +2056,7 @@ static struct callattempt *wait_for_answer(struct queue_ent *qe, struct callatte
 							if (in->cdr)
 								ast_cdr_busy(in->cdr);
 							do_hang(o);
-							endtime = (long)time(NULL);
+							endtime = (long) time(NULL);
 							endtime -= starttime;
 							rna(endtime*1000, qe, on, membername);
 							if (qe->parent->strategy != QUEUE_STRATEGY_RINGALL) {
@@ -2071,7 +2071,7 @@ static struct callattempt *wait_for_answer(struct queue_ent *qe, struct callatte
 								ast_verbose( VERBOSE_PREFIX_3 "%s is circuit-busy\n", o->chan->name);
 							if (in->cdr)
 								ast_cdr_busy(in->cdr);
-							endtime = (long)time(NULL);
+							endtime = (long) time(NULL);
 							endtime -= starttime;
 							rna(endtime*1000, qe, on, membername);
 							do_hang(o);
@@ -2236,7 +2236,7 @@ static int wait_our_turn(struct queue_ent *qe, int ringing, enum queue_result *r
 		/* leave the queue if no agents, if enabled */
 		if (qe->parent->leavewhenempty && (stat == QUEUE_NO_MEMBERS)) {
 			*reason = QUEUE_LEAVEEMPTY;
-			ast_queue_log(qe->parent->name, qe->chan->uniqueid, "NONE", "EXITEMPTY", "%d|%d|%ld", qe->pos, qe->opos, (long)time(NULL) - qe->start);
+			ast_queue_log(qe->parent->name, qe->chan->uniqueid, "NONE", "EXITEMPTY", "%d|%d|%ld", qe->pos, qe->opos, (long) time(NULL) - qe->start);
 			leave_queue(qe);
 			break;
 		}
@@ -2244,13 +2244,13 @@ static int wait_our_turn(struct queue_ent *qe, int ringing, enum queue_result *r
 		/* leave the queue if no reachable agents, if enabled */
 		if ((qe->parent->leavewhenempty == QUEUE_EMPTY_STRICT) && (stat == QUEUE_NO_REACHABLE_MEMBERS || stat == QUEUE_NO_UNPAUSED_REACHABLE_MEMBERS)) {
 			*reason = QUEUE_LEAVEUNAVAIL;
-			ast_queue_log(qe->parent->name, qe->chan->uniqueid, "NONE", "EXITEMPTY", "%d|%d|%ld", qe->pos, qe->opos, (long)time(NULL) - qe->start);
+			ast_queue_log(qe->parent->name, qe->chan->uniqueid, "NONE", "EXITEMPTY", "%d|%d|%ld", qe->pos, qe->opos, (long) time(NULL) - qe->start);
 			leave_queue(qe);
 			break;
 		}
 		if ((qe->parent->leavewhenempty == QUEUE_EMPTY_LOOSE) && (stat == QUEUE_NO_REACHABLE_MEMBERS)) {
 			*reason = QUEUE_LEAVEUNAVAIL;
-			ast_queue_log(qe->parent->name, qe->chan->uniqueid, "NONE", "EXITEMPTY", "%d|%d|%ld", qe->pos, qe->opos, (long)time(NULL) - qe->start);
+			ast_queue_log(qe->parent->name, qe->chan->uniqueid, "NONE", "EXITEMPTY", "%d|%d|%ld", qe->pos, qe->opos, (long) time(NULL) - qe->start);
 			leave_queue(qe);
 			break;
 		}
@@ -2580,7 +2580,7 @@ static int try_calling(struct queue_ent *qe, const char *options, char *announce
 			} else if (res2) {
 				/* Caller must have hung up just before being connected*/
 				ast_log(LOG_NOTICE, "Caller was about to talk to agent on %s but the caller hungup.\n", peer->name);
-				ast_queue_log(queuename, qe->chan->uniqueid, member->membername, "ABANDON", "%d|%d|%ld", qe->pos, qe->opos, (long)time(NULL) - qe->start);
+				ast_queue_log(queuename, qe->chan->uniqueid, member->membername, "ABANDON", "%d|%d|%ld", qe->pos, qe->opos, (long) time(NULL) - qe->start);
 				record_abandoned(qe);
 				ast_hangup(peer);
 				return -1;
@@ -2711,7 +2711,7 @@ static int try_calling(struct queue_ent *qe, const char *options, char *announce
 		/* use  pbx_builtin_setvar to set a load of variables with one call */
 		if (qe->parent->setqueueentryvar) {
 			snprintf(interfacevar,sizeof(interfacevar), "QEHOLDTIME=%ld|QEORIGINALPOS=%d",
-				(long)time(NULL) - qe->start, qe->opos);
+				(long) time(NULL) - qe->start, qe->opos);
 			pbx_builtin_setvar(qe->chan, interfacevar);
 		}
 	
@@ -2766,7 +2766,7 @@ static int try_calling(struct queue_ent *qe, const char *options, char *announce
 			} else
 				ast_log(LOG_WARNING, "Asked to execute an AGI on this channel, but could not find application (agi)!\n");
 		}
-		ast_queue_log(queuename, qe->chan->uniqueid, member->membername, "CONNECT", "%ld|%s", (long)time(NULL) - qe->start, peer->uniqueid);
+		ast_queue_log(queuename, qe->chan->uniqueid, member->membername, "CONNECT", "%ld|%s", (long) time(NULL) - qe->start, peer->uniqueid);
 		if (qe->parent->eventwhencalled)
 			manager_event(EVENT_FLAG_AGENT, "AgentConnect",
 					"Queue: %s\r\n"
@@ -2778,7 +2778,7 @@ static int try_calling(struct queue_ent *qe, const char *options, char *announce
 					"BridgedChannel: %s\r\n"
 					"%s",
 					queuename, qe->chan->uniqueid, peer->name, member->interface, member->membername,
-					(long)time(NULL) - qe->start, peer->uniqueid,
+					(long) time(NULL) - qe->start, peer->uniqueid,
 					qe->parent->eventwhencalled == QUEUE_EVENT_VARIABLES ? vars2manager(qe->chan, vars, sizeof(vars)) : "");
 		ast_copy_string(oldcontext, qe->chan->context, sizeof(oldcontext));
 		ast_copy_string(oldexten, qe->chan->exten, sizeof(oldexten));
@@ -3521,7 +3521,8 @@ check_turns:
 			if (!res)
 				break;
 			if (valid_exit(&qe, res)) {
-				ast_queue_log(args.queuename, chan->uniqueid, "NONE", "EXITWITHKEY", "%s|%d", qe.digits, qe.pos);
+				ast_queue_log(args.queuename, chan->uniqueid, "NONE", "EXITWITHKEY", "%s|%d|%d|%ld", 
+					qe.digits, qe.pos, qe.opos, (long) time(NULL) - qe.start);
 				break;
 			}
 		}
@@ -3541,7 +3542,8 @@ check_turns:
 					record_abandoned(&qe);
 					reason = QUEUE_TIMEOUT;
 					res = 0;
-					ast_queue_log(args.queuename, chan->uniqueid, "NONE", "EXITWITHTIMEOUT", "%d", qe.pos);
+					ast_queue_log(args.queuename, chan->uniqueid,"NONE", "EXITWITHTIMEOUT", "%d|%d|%ld", 
+						qe.pos, qe.opos, (long) time(NULL) - qe.start);
 					break;
 				}
 
@@ -3549,7 +3551,8 @@ check_turns:
 					/* Make a position announcement, if enabled */
 					if (qe.parent->announcefrequency && !ringing &&
 						(res = say_position(&qe))) {
-						ast_queue_log(args.queuename, chan->uniqueid, "NONE", "EXITWITHKEY", "%s|%d", qe.digits, qe.pos);
+						ast_queue_log(args.queuename, chan->uniqueid, "NONE", "EXITWITHKEY", "%s|%d|%d|%ld", 
+							qe.digits, qe.pos, qe.opos, (long) time(NULL) - qe.start);
 						break;
 					}
 
@@ -3559,7 +3562,8 @@ check_turns:
 				/* Make a periodic announcement, if enabled */
 				if (qe.parent->periodicannouncefrequency && !ringing &&
 					(res = say_periodic_announcement(&qe))) {
-					ast_queue_log(args.queuename, chan->uniqueid, "NONE", "EXITWITHKEY", "%c|%d", res, qe.pos);
+					ast_queue_log(args.queuename, chan->uniqueid, "NONE", "EXITWITHKEY", "%s|%d|%d|%ld", 
+						qe.digits, qe.pos, qe.opos, (long) time(NULL) - qe.start);
 					break;
 				}
 
@@ -3574,8 +3578,8 @@ check_turns:
 								(long) time(NULL) - qe.start);
 						}
 					} else if (valid_exit(&qe, res)) {
-						ast_queue_log(args.queuename, chan->uniqueid, "NONE", "EXITWITHKEY",
-							"%s|%d", qe.digits, qe.pos);
+						ast_queue_log(args.queuename, chan->uniqueid, "NONE", "EXITWITHKEY", "%s|%d|%d|%ld", 
+							qe.digits, qe.pos, qe.opos, (long) time(NULL) - qe.start);
 					}
 					break;
 				}
@@ -3609,7 +3613,7 @@ check_turns:
 					record_abandoned(&qe);
 					reason = QUEUE_TIMEOUT;
 					res = 0;
-					ast_queue_log(args.queuename, chan->uniqueid, "NONE", "EXITWITHTIMEOUT", "%d", qe.pos);
+					ast_queue_log(qe.parent->name, qe.chan->uniqueid,"NONE", "EXITWITHTIMEOUT", "%d|%d|%ld", qe.pos, qe.opos, (long) time(NULL) - qe.start);
 					break;
 				}
 
@@ -3617,7 +3621,7 @@ check_turns:
 				res = wait_a_bit(&qe);
 				if (res < 0) {
 					record_abandoned(&qe);
-					ast_queue_log(args.queuename, chan->uniqueid, "NONE", "ABANDON", "%d|%d|%ld", qe.pos, qe.opos, (long)time(NULL) - qe.start);
+					ast_queue_log(args.queuename, chan->uniqueid, "NONE", "ABANDON", "%d|%d|%ld", qe.pos, qe.opos, (long) time(NULL) - qe.start);
 					if (option_verbose > 2) {
 						ast_verbose(VERBOSE_PREFIX_3 "User disconnected from queue %s when they almost made it\n", args.queuename);
 					}
@@ -3625,14 +3629,16 @@ check_turns:
 					break;
 				}
 				if (res && valid_exit(&qe, res)) {
-					ast_queue_log(args.queuename, chan->uniqueid, "NONE", "EXITWITHKEY", "%s|%d", qe.digits, qe.pos);
+					ast_queue_log(args.queuename, chan->uniqueid, "NONE", "EXITWITHKEY", "%s|%d|%d|%ld", 
+						qe.digits, qe.pos, qe.opos, (long) time(NULL) - qe.start);
 					break;
 				}
 				/* exit after 'timeout' cycle if 'n' option enabled */
 				if (go_on) {
 					if (option_verbose > 2)
 						ast_verbose(VERBOSE_PREFIX_3 "Exiting on time-out cycle\n");
-					ast_queue_log(args.queuename, chan->uniqueid, "NONE", "EXITWITHTIMEOUT", "%d", qe.pos);
+					ast_queue_log(args.queuename, chan->uniqueid, "NONE", "EXITWITHTIMEOUT", "%d|%d|%ld", 
+						qe.pos, qe.opos, (long) time(NULL) - qe.start);
 					record_abandoned(&qe);
 					reason = QUEUE_TIMEOUT;
 					res = 0;
diff --git a/doc/queuelog.tex b/doc/queuelog.tex
index 79d9ff532..dd2047af6 100644
--- a/doc/queuelog.tex
+++ b/doc/queuelog.tex
@@ -66,12 +66,15 @@ queue when they hungup, the origposition is the original position the
 caller was when they first entered the queue, and the waittime is how 
 long the call had been waiting in the queue at the time of disconnect.
 
-EXITWITHKEY(key|position)
+EXITWITHKEY(key|position|origposition|waittime)
 The caller elected to use a menu key to exit the queue.  The key and
-the caller's position in the queue are recorded.
+the caller's position in the queue are recorded.  The caller's entry
+position and amoutn of time waited is also recorded.
 
-EXITWITHTIMEOUT(position)
-The caller was on hold too long and the timeout expired.
+EXITWITHTIMEOUT(position|origposition|waittime)
+The caller was on hold too long and the timeout expired.  The position in the
+queue when the timeout occurred, the entry position, and the amount of time
+waited are logged.
 
 QUEUESTART
 The queueing system has been started for the first time this session.