app_queue: Fix members showing as being in call when not.
authorJoshua Colp <jcolp@digium.com>
Mon, 15 May 2017 20:03:36 +0000 (20:03 +0000)
committerJoshua Colp <jcolp@digium.com>
Tue, 23 May 2017 14:24:22 +0000 (09:24 -0500)
A change was done which added an 'in_call' flag to queue
members that was set to true while talking to an agent.
Unfortunately in practice this does not accurately reflect
whether they are talking to an agent or not. If a Local
channel is involved and a transfer is performed then the
app_queue application would incorrectly think the agent
was still in a call with the caller. This was done to
fix a race condition between an agent becoming available
by device state and the checking of the last call information
for the wrapup time. There was a small window where the
last call information would be the previous value instead
of the new one.

This change goes about fixing the original issue in a
different way by considering the call completed if device
state is received which would make the agent available
and if they are currently in a call. If this occurs the
last call information is updated before the agent becomes
available ensuring that old information is not present
when checking if the member should be called. This also
improves the transfer situation by actually updating
and enforcing the wrapup time.

ASTERISK-26399
ASTERISK-26400
ASTERISK-26715
ASTERISK-26975

Change-Id: Ife1cb686e3173b3a6d368601adef9aff69d4beea

apps/app_queue.c

index 0f46d28..0e0b801 100644 (file)
@@ -1570,10 +1570,11 @@ struct member {
        int paused;                          /*!< Are we paused (not accepting calls)? */
        char reason_paused[80];              /*!< Reason of paused if member is paused */
        int queuepos;                        /*!< In what order (pertains to certain strategies) should this member be called? */
+       int callcompletedinsl;               /*!< Whether the current call was completed within service level */
+       time_t starttime;                    /*!< The time at which the member answered the current caller. */
        time_t lastcall;                     /*!< When last successful call was hungup */
        time_t lastpause;                    /*!< When started the last pause */
-       unsigned int in_call:1;              /*!< True if member is still in call. (so lastcall is not actual) */
-       struct call_queue *lastqueue;        /*!< Last queue we received a call */
+       struct call_queue *lastqueue;        /*!< Last queue we received a call */
        unsigned int dead:1;                 /*!< Used to detect members deleted in realtime */
        unsigned int delme:1;                /*!< Flag to delete entry on reload */
        char rt_uniqueid[80];                /*!< Unique id of realtime member entry */
@@ -1729,6 +1730,7 @@ static struct ao2_container *queues;
 static void update_realtime_members(struct call_queue *q);
 static struct member *interface_exists(struct call_queue *q, const char *interface);
 static int set_member_paused(const char *queuename, const char *interface, const char *reason, int paused);
+static int update_queue(struct call_queue *q, struct member *member, int callcompletedinsl, time_t starttime);
 
 static struct member *find_member_by_queuename_and_interface(const char *queuename, const char *interface);
 /*! \brief sets the QUEUESTATUS channel variable */
@@ -2220,7 +2222,7 @@ static struct ast_json *queue_member_blob_create(struct call_queue *q, struct me
                "CallsTaken", mem->calls,
                "LastCall", (int)mem->lastcall,
                "LastPause", (int)mem->lastpause,
-               "InCall", mem->in_call,
+               "InCall", mem->starttime ? 1 : 0,
                "Status", mem->status,
                "Paused", mem->paused,
                "PausedReason", mem->reason_paused,
@@ -2284,10 +2286,6 @@ static int get_member_status(struct call_queue *q, int max_penalty, int min_pena
                        if (member->paused && (conditions & QUEUE_EMPTY_PAUSED)) {
                                ast_debug(4, "%s is unavailable because he is paused'\n", member->membername);
                                break;
-                       } else if ((conditions & QUEUE_EMPTY_WRAPUP) && member->in_call && q->wrapuptime) {
-                               ast_debug(4, "%s is unavailable because still in call, so we can`t check "
-                                       "wrapuptime (%d)\n", member->membername, q->wrapuptime);
-                               break;
                        } else if ((conditions & QUEUE_EMPTY_WRAPUP) && member->lastcall && q->wrapuptime && (time(NULL) - q->wrapuptime < member->lastcall)) {
                                ast_debug(4, "%s is unavailable because it has only been %d seconds since his last call (wrapup time is %d)\n", member->membername, (int) (time(NULL) - member->lastcall), q->wrapuptime);
                                break;
@@ -2384,6 +2382,14 @@ static void pending_members_remove(struct member *mem)
 static void update_status(struct call_queue *q, struct member *m, const int status)
 {
        if (m->status != status) {
+               /* If this member has transitioned to being available then update their queue
+                * information. If they are currently in a call then the leg to the agent will be
+                * considered done and the call finished.
+                */
+               if (status == AST_DEVICE_NOT_INUSE) {
+                       update_queue(q, m, m->callcompletedinsl, m->starttime);
+               }
+
                m->status = status;
 
                /* Remove the member from the pending members pool only when the status changes.
@@ -2430,9 +2436,6 @@ static int is_member_available(struct call_queue *q, struct member *mem)
        }
 
        /* Let wrapuptimes override device state availability */
-       if (q->wrapuptime && mem->in_call) {
-               available = 0; /* member is still in call, cant check wrapuptime to lastcall time */
-       }
        if (mem->lastcall && q->wrapuptime && (time(NULL) - q->wrapuptime < mem->lastcall)) {
                available = 0;
        }
@@ -2791,8 +2794,9 @@ static void clear_queue(struct call_queue *q)
                struct ao2_iterator mem_iter = ao2_iterator_init(q->members, 0);
                while ((mem = ao2_iterator_next(&mem_iter))) {
                        mem->calls = 0;
+                       mem->callcompletedinsl = 0;
                        mem->lastcall = 0;
-                       mem->in_call = 0;
+                       mem->starttime = 0;
                        ao2_ref(mem, -1);
                }
                ao2_iterator_destroy(&mem_iter);
@@ -4275,12 +4279,6 @@ static int can_ring_entry(struct queue_ent *qe, struct callattempt *call)
                return 0;
        }
 
-       if (call->member->in_call && call->lastqueue && call->lastqueue->wrapuptime) {
-               ast_debug(1, "%s is in call, so not available (wrapuptime %d)\n",
-                       call->interface, call->lastqueue->wrapuptime);
-               return 0;
-       }
-
        if ((call->lastqueue && call->lastqueue->wrapuptime && (time(NULL) - call->lastcall < call->lastqueue->wrapuptime))
                || (!call->lastqueue && qe->parent->wrapuptime && (time(NULL) - call->lastcall < qe->parent->wrapuptime))) {
                ast_debug(1, "Wrapuptime not yet expired on queue %s for %s\n",
@@ -5522,14 +5520,22 @@ static int wait_our_turn(struct queue_ent *qe, int ringing, enum queue_result *r
  * \brief update the queue status
  * \retval Always 0
 */
-static int update_queue(struct call_queue *q, struct member *member, int callcompletedinsl, int newtalktime)
+static int update_queue(struct call_queue *q, struct member *member, int callcompletedinsl, time_t starttime)
 {
        int oldtalktime;
-
+       int newtalktime = time(NULL) - starttime;
        struct member *mem;
        struct call_queue *qtmp;
        struct ao2_iterator queue_iter;
 
+       /* It is possible for us to be called when a call has already been considered terminated
+        * and data updated, so to ensure we only act on the call that the agent is currently in
+        * we check when the call was bridged.
+        */
+       if (!starttime || (member->starttime != starttime)) {
+               return 0;
+       }
+
        if (shared_lastcall) {
                queue_iter = ao2_iterator_init(queues, 0);
                while ((qtmp = ao2_t_iterator_next(&queue_iter, "Iterate through queues"))) {
@@ -5537,10 +5543,9 @@ static int update_queue(struct call_queue *q, struct member *member, int callcom
                        if ((mem = ao2_find(qtmp->members, member, OBJ_POINTER))) {
                                time(&mem->lastcall);
                                mem->calls++;
+                               mem->callcompletedinsl = 0;
+                               mem->starttime = 0;
                                mem->lastqueue = q;
-                               mem->in_call = 0;
-                               ast_debug(4, "Marked member %s as NOT in_call. Lastcall time: %ld \n",
-                                       mem->membername, (long)mem->lastcall);
                                ao2_ref(mem, -1);
                        }
                        ao2_unlock(qtmp);
@@ -5550,11 +5555,10 @@ static int update_queue(struct call_queue *q, struct member *member, int callcom
        } else {
                ao2_lock(q);
                time(&member->lastcall);
+               member->callcompletedinsl = 0;
                member->calls++;
+               member->starttime = 0;
                member->lastqueue = q;
-               member->in_call = 0;
-               ast_debug(4, "Marked member %s as NOT in_call. Lastcall time: %ld \n",
-                       member->membername, (long)member->lastcall);
                ao2_unlock(q);
        }
        /* Member might never experience any direct status change (local
@@ -6012,7 +6016,7 @@ static void handle_blind_transfer(void *userdata, struct stasis_subscription *su
        send_agent_complete(queue_data->queue->name, caller_snapshot, member_snapshot, queue_data->member,
                        queue_data->holdstart, queue_data->starttime, TRANSFER);
        update_queue(queue_data->queue, queue_data->member, queue_data->callcompletedinsl,
-                       time(NULL) - queue_data->starttime);
+                       queue_data->starttime);
        remove_stasis_subscriptions(queue_data);
 }
 
@@ -6072,7 +6076,7 @@ static void handle_attended_transfer(void *userdata, struct stasis_subscription
        send_agent_complete(queue_data->queue->name, caller_snapshot, member_snapshot, queue_data->member,
                        queue_data->holdstart, queue_data->starttime, TRANSFER);
        update_queue(queue_data->queue, queue_data->member, queue_data->callcompletedinsl,
-                       time(NULL) - queue_data->starttime);
+                       queue_data->starttime);
        remove_stasis_subscriptions(queue_data);
 }
 
@@ -6273,7 +6277,7 @@ static void handle_hangup(void *userdata, struct stasis_subscription *sub,
        send_agent_complete(queue_data->queue->name, caller_snapshot, member_snapshot, queue_data->member,
                        queue_data->holdstart, queue_data->starttime, reason);
        update_queue(queue_data->queue, queue_data->member, queue_data->callcompletedinsl,
-                       time(NULL) - queue_data->starttime);
+                       queue_data->starttime);
        remove_stasis_subscriptions(queue_data);
 }
 
@@ -6534,7 +6538,6 @@ static int try_calling(struct queue_ent *qe, struct ast_flags opts, char **opt_a
        int x=0;
        char *announce = NULL;
        char digit = 0;
-       time_t callstart;
        time_t now = time(NULL);
        struct ast_bridge_config bridge_config;
        char nondataquality = 1;
@@ -6545,12 +6548,10 @@ static int try_calling(struct queue_ent *qe, struct ast_flags opts, char **opt_a
        char tmpid[256];
        int forwardsallowed = 1;
        int block_connected_line = 0;
-       int callcompletedinsl;
        struct ao2_iterator memi;
        struct queue_end_bridge *queue_end_bridge = NULL;
-       struct ao2_iterator queue_iter; /* to iterate through all queues (for shared_lastcall)*/
-       struct member *mem;
-       struct call_queue *queuetmp;
+       int callcompletedinsl;
+       time_t starttime;
 
        memset(&bridge_config, 0, sizeof(bridge_config));
        tmpid[0] = 0;
@@ -6739,10 +6740,10 @@ static int try_calling(struct queue_ent *qe, struct ast_flags opts, char **opt_a
                /* Update parameters for the queue */
                time(&now);
                recalc_holdtime(qe, (now - qe->start));
+               member = lpeer->member;
                ao2_lock(qe->parent);
-               callcompletedinsl = ((now - qe->start) <= qe->parent->servicelevel);
+               callcompletedinsl = member->callcompletedinsl = ((now - qe->start) <= qe->parent->servicelevel);
                ao2_unlock(qe->parent);
-               member = lpeer->member;
                /* Increment the refcount for this member, since we're going to be using it for awhile in here. */
                ao2_ref(member, 1);
                hangupcalls(qe, outgoing, peer, qe->cancel_answered_elsewhere);
@@ -6978,27 +6979,6 @@ static int try_calling(struct queue_ent *qe, struct ast_flags opts, char **opt_a
                }
                qe->handled++;
 
-               /** mark member as "in_call" in all queues */
-               if (shared_lastcall) {
-                       queue_iter = ao2_iterator_init(queues, 0);
-                       while ((queuetmp = ao2_t_iterator_next(&queue_iter, "Iterate through queues"))) {
-                               ao2_lock(queuetmp);
-                               if ((mem = ao2_find(queuetmp->members, member, OBJ_POINTER))) {
-                                       mem->in_call = 1;
-                                       ast_debug(4, "Marked member %s as in_call \n", mem->membername);
-                                       ao2_ref(mem, -1);
-                               }
-                               ao2_unlock(queuetmp);
-                               queue_t_unref(queuetmp, "Done with iterator");
-                       }
-                       ao2_iterator_destroy(&queue_iter);
-               } else {
-                       ao2_lock(qe->parent);
-                       member->in_call = 1;
-                       ast_debug(4, "Marked member %s as in_call \n", member->membername);
-                       ao2_unlock(qe->parent);
-               }
-
                ast_queue_log(queuename, ast_channel_uniqueid(qe->chan), member->membername, "CONNECT", "%ld|%s|%ld", (long) (time(NULL) - qe->start), ast_channel_uniqueid(peer),
                                                                                                        (long)(orig - to > 0 ? (orig - to) / 1000 : 0));
 
@@ -7026,8 +7006,16 @@ static int try_calling(struct queue_ent *qe, struct ast_flags opts, char **opt_a
                        queue_t_ref(qe->parent, "For bridge_config reference");
                }
 
-               time(&callstart);
-               setup_stasis_subs(qe, peer, member, qe->start, callstart, callcompletedinsl);
+               ao2_lock(qe->parent);
+               time(&member->starttime);
+               starttime = member->starttime;
+               ao2_unlock(qe->parent);
+               /* As a queue member may end up in multiple calls at once if a transfer occurs with
+                * a Local channel in the mix we pass the current call information (starttime) to the
+                * Stasis subscriptions so when they update the queue member data it becomes a noop
+                * if this call is no longer between the caller and the queue member.
+                */
+               setup_stasis_subs(qe, peer, member, qe->start, starttime, callcompletedinsl);
                bridge = ast_bridge_call_with_flags(qe->chan, peer, &bridge_config,
                                AST_BRIDGE_FLAG_MERGE_INHIBIT_FROM | AST_BRIDGE_FLAG_MERGE_INHIBIT_TO | AST_BRIDGE_FLAG_SWAP_INHIBIT_FROM);
 
@@ -9469,7 +9457,7 @@ static char *__queues_show(struct mansession *s, int fd, int argc, const char *
                                ast_str_append(&out, 0, "%s%s%s%s%s%s%s%s%s",
                                        mem->dynamic ? ast_term_color(COLOR_CYAN, COLOR_BLACK) : "", mem->dynamic ? " (dynamic)" : "", ast_term_reset(),
                                        mem->realtime ? ast_term_color(COLOR_MAGENTA, COLOR_BLACK) : "", mem->realtime ? " (realtime)" : "", ast_term_reset(),
-                                       mem->in_call ? ast_term_color(COLOR_BROWN, COLOR_BLACK) : "", mem->in_call ? " (in call)" : "", ast_term_reset());
+                                       mem->starttime ? ast_term_color(COLOR_BROWN, COLOR_BLACK) : "", mem->starttime ? " (in call)" : "", ast_term_reset());
                                if (mem->paused) {
                                        if (ast_strlen_zero(mem->reason_paused)) {
                                                ast_str_append(&out, 0, " %s(paused was %ld secs ago)%s",
@@ -9860,7 +9848,7 @@ static int manager_queues_status(struct mansession *s, const struct message *m)
                                                "%s"
                                                "\r\n",
                                                q->name, mem->membername, mem->interface, mem->state_interface, mem->dynamic ? "dynamic" : "static",
-                                               mem->penalty, mem->calls, (int)mem->lastcall, (int)mem->lastpause, mem->in_call, mem->status,
+                                               mem->penalty, mem->calls, (int)mem->lastcall, (int)mem->lastpause, mem->starttime ? 1 : 0, mem->status,
                                                mem->paused, mem->reason_paused, idText);
                                        ++q_items;
                                }