WHISTLE-1441: normalize key creation

WHISTLE-1441: more logging for config changes

WHISTLE-1441: more logging for queue handling

WHISTLE-1441: track statuses in a list

WHISTLE-1441: dialyzer update

WHISTLE-1441: update agent ring timer fudge and default

WHISTLE-1441: only send the accept when the agent has answered its leg

WHISTLE-1441: update todos

WHISTLE-1441: normalize key creation

whistle_apps/apps/acdc/doc/TODO.txt

@@ -1,5 +1,3 @@
-Race condition when agent has answered leg, send acceptance before uuid_bridge.
-
 ** Scenario 1
  * No agents logged in
  * Customer calls in...eventually hangs up

whistle_apps/apps/acdc/src/acdc_agent_fsm.erl

@@ -453,11 +453,8 @@ ringing({originate_failed, JObj}, #state{agent_proc=Srv
 
     {next_state, ready, clear_call(State)};
 
-ringing({channel_bridged, CallId}, #state{agent_proc=Srv
-                                          ,member_call_id=CallId
-                                         }=State) ->
+ringing({channel_bridged, CallId}, #state{member_call_id=CallId}=State) ->
     lager:debug("agent has connected to member"),
-    acdc_agent:member_connect_accepted(Srv),
     {next_state, answered, State};
 
 ringing({channel_hungup, CallId}, #state{agent_proc=Srv
@@ -507,7 +504,7 @@ ringing({channel_answered, ACallId}, #state{agent_call_id=ACallId
     lager:debug("agent channel ready: ~s", [ACallId]),
     acdc_agent:join_agent(Srv, ACallId),
     acdc_agent:member_connect_accepted(Srv),
-    {next_state, ringing, State};
+    {next_state, answered, State};
 
 ringing({channel_answered, MCallId}, #state{member_call_id=MCallId}=State) ->
     lager:debug("member channel answered"),
@@ -816,11 +813,7 @@ handle_info(_Info, StateName, State) ->
 %% @spec terminate(Reason, StateName, State) -> void()
 %% @end
 %%--------------------------------------------------------------------
-terminate(_Reason, _StateName, #state{acct_id=AcctId
-                                      ,agent_id=AgentId
-                                      ,agent_proc=Srv
-                                      }) ->
-    acdc_stats:agent_inactive(AcctId, AgentId),
+terminate(_Reason, _StateName, #state{agent_proc=Srv}) ->
     acdc_agent:stop(Srv),
     lager:debug("acdc agent fsm terminating while in ~s: ~p", [_StateName, _Reason]).
 

whistle_apps/apps/acdc/src/acdc_agent_handler.erl

@@ -65,24 +65,25 @@ maybe_stop_agent(AcctId, AgentId) ->
     case acdc_agents_sup:find_agent_supervisor(AcctId, AgentId) of
         undefined -> lager:debug("agent ~s (~s) not found, nothing to do", [AgentId, AcctId]);
         P when is_pid(P) ->
-            acdc_stats:agent_inactive(AcctId, AgentId),
-            acdc_agent_sup:stop(P)
+            lager:debug("agent ~s(~s) is logging out, stopping ~p", [AcctId, AgentId, P]),
+            _ = acdc_agent_sup:stop(P),
+            acdc_stats:agent_inactive(AcctId, AgentId)
     end.
 
 maybe_pause_agent(AcctId, AgentId, Timeout) ->
     case acdc_agents_sup:find_agent_supervisor(AcctId, AgentId) of
         undefined -> lager:debug("agent ~s (~s) not found, nothing to do", [AgentId, AcctId]);
         P when is_pid(P) ->
-            FSM = acdc_agent_sup:fsm(P),
-            acdc_agent_fsm:pause(FSM, Timeout)
+            lager:debug("agent ~s(~s) is pausing for ~p", [AcctId, AgentId, Timeout]),
+            acdc_agent_fsm:pause(acdc_agent_sup:fsm(P), Timeout)
     end.
 
 maybe_resume_agent(AcctId, AgentId) ->
     case acdc_agents_sup:find_agent_supervisor(AcctId, AgentId) of
         undefined -> lager:debug("agent ~s (~s) not found, nothing to do", [AgentId, AcctId]);
         P when is_pid(P) ->
-            FSM = acdc_agent_sup:fsm(P),
-            acdc_agent_fsm:resume(FSM)
+            lager:debug("agent ~s(~s) is resuming: ~p", [AcctId, AgentId, P]),
+            acdc_agent_fsm:resume(acdc_agent_sup:fsm(P))
     end.
 
 -spec handle_sync_req/2 :: (wh_json:json_object(), wh_proplist()) -> 'ok'.
@@ -178,5 +179,8 @@ handle_agent_change(JObj, AcctId, AgentId, <<"doc_edited">>) ->
 handle_agent_change(_JObj, AcctId, AgentId, <<"doc_deleted">>) ->
     case acdc_agents_sup:find_agent_supervisor(AcctId, AgentId) of
         undefined -> ok;
-        P when is_pid(P) -> acdc_agent_sup:stop(P)
+        P when is_pid(P) ->
+            lager:debug("agent ~s(~s) has been deleted, stopping ~p", [AcctId, AgentId, P]),
+            _ = acdc_agent_sup:stop(P),
+            acdc_stats:agent_inactive(AcctId, AgentId)
     end.

whistle_apps/apps/acdc/src/acdc_queue_fsm.erl

@@ -77,7 +77,7 @@
          %% Config options
          ,name :: ne_binary()
          ,connection_timeout :: pos_integer()
-         ,agent_ring_timeout = 5 :: pos_integer() % how long to ring an agent before giving up
+         ,agent_ring_timeout = 10 :: pos_integer() % how long to ring an agent before giving up
          ,max_queue_size = 0 :: integer() % restrict the number of the queued callers
          ,ring_simultaneously = 1 :: integer() % how many agents to try ringing at a time (first one wins)
          ,enter_when_empty = true :: boolean() % if a queue is agent-less, can the caller enter?
@@ -797,7 +797,7 @@ agent_ring_timeout(_) -> ?AGENT_RING_TIMEOUT.
 
 -spec start_agent_ring_timer/1 :: (pos_integer()) -> reference().
 start_agent_ring_timer(AgentTimeout) ->
-    gen_fsm:start_timer(AgentTimeout * 1500, ?AGENT_RING_TIMEOUT_MESSAGE).
+    gen_fsm:start_timer(AgentTimeout * 2600, ?AGENT_RING_TIMEOUT_MESSAGE).
 
 -spec maybe_stop_timer/1 :: (reference() | 'undefined') -> 'ok'.
 maybe_stop_timer(undefined) -> ok;

whistle_apps/apps/acdc/src/acdc_queue_handler.erl

@@ -62,8 +62,10 @@ handle_queue_change(JObj, AcctId, QueueId, <<"doc_edited">>) ->
     end;
 handle_queue_change(_JObj, AcctId, QueueId, <<"doc_deleted">>) ->
     case acdc_queues_sup:find_queue_supervisor(AcctId, QueueId) of
-        undefined -> ok;
-        P when is_pid(P) -> acdc_queue_sup:stop(P)
+        undefined -> lager:debug("no queue(~s) started for account ~s", [QueueId, AcctId]);
+        P when is_pid(P) ->
+            lager:debug("stopping queue(~s) in account ~s (deleted): ~p", [QueueId, AcctId, P]),
+            acdc_queue_sup:stop(P)
     end.
 
 handle_stats_req(JObj, _Props) ->

whistle_apps/apps/acdc/src/acdc_stats.erl

@@ -229,7 +229,6 @@ agent_active(AcctId, AgentId) ->
 agent_inactive(AcctId, AgentId) ->
     gen_listener:cast(?MODULE, {store, #stat{acct_id=AcctId
                                              ,agent_id=AgentId
-                                             ,active_since=wh_util:current_tstamp()
                                              ,name=agent_inactive
                                             }
                                }).
@@ -387,45 +386,38 @@ write_account_doc({AcctId, AcctJObj}, TStamp) ->
 update_stat(AcctDocs, #stat{name=agent_active
                             ,acct_id=AcctId
                             ,agent_id=AgentId
+                            ,timestamp=TStamp
                            }) ->
-    AcctDoc = fetch_acct_doc(AcctId, AcctDocs),
-
-    ActiveKey = [<<"agents">>, AgentId, <<"status">>],
-
     dict:store(AcctId
-               ,wh_json:set_value(ActiveKey, <<"login">>, AcctDoc)
+               ,update_status(fetch_acct_doc(AcctId, AcctDocs), AgentId, TStamp, <<"login">>)
                ,AcctDocs
               );
+
 update_stat(AcctDocs, #stat{name=agent_inactive
                             ,acct_id=AcctId
                             ,agent_id=AgentId
+                            ,timestamp=TStamp
                            }) ->
-    AcctDoc = fetch_acct_doc(AcctId, AcctDocs),
-
-    InactiveKey = [<<"agents">>, AgentId, <<"status">>],
-
     dict:store(AcctId
-               ,wh_json:set_value(InactiveKey, <<"logout">>, AcctDoc)
+               ,update_status(fetch_acct_doc(AcctId, AcctDocs), AgentId, TStamp, <<"logout">>)
                ,AcctDocs
               );
 
 update_stat(AcctDocs, #stat{name=agent_paused
                             ,acct_id=AcctId
                             ,agent_id=AgentId
-                            ,active_since=ActiveSince
+                            ,timestamp=TStamp
                             ,elapsed=Timeout
                            }) ->
-    AcctDoc = fetch_acct_doc(AcctId, AcctDocs),
-
-    PauseKey = [<<"agents">>, AgentId, <<"status">>],
     TimeoutKey = [<<"agents">>, AgentId, <<"timeout">>],
     TimeLeftKey = [<<"agents">>, AgentId, <<"time_left">>],
 
     dict:store(AcctId
-               ,wh_json:set_values([{PauseKey, <<"paused">>}
-                                    ,{TimeoutKey, Timeout}
-                                    ,{TimeLeftKey, wh_util:elapsed_s(ActiveSince)}
-                                   ], AcctDoc)
+               ,wh_json:set_values([{TimeoutKey, Timeout}
+                                    ,{TimeLeftKey, wh_util:elapsed_s(TStamp)}
+                                   ]
+                                   ,update_status(fetch_acct_doc(AcctId, AcctDocs), AgentId, TStamp, <<"paused">>)
+                                  )
                ,AcctDocs
               );
 
@@ -652,3 +644,8 @@ add_agent_wrapup_time_on_break(AcctDoc, AgentId, Elapsed) ->
 add_agent_wrapup_time_left(AcctDoc, AgentId, WaitTimeLeft) ->
     WaitKey = [<<"agents">>, AgentId, <<"wrapup_time_left">>],
     wh_json:set_value(WaitKey, WaitTimeLeft, AcctDoc).
+
+update_status(AcctDoc, AgentId, TStamp, Status) ->
+    StatusKey = [<<"agents">>, AgentId, <<"statuses">>],
+    Statuses = wh_json:get_value(StatusKey, AcctDoc, []),
+    wh_json:set_value(StatusKey, [{TStamp, Status} | Statuses], AcctDoc).