Hey Everyone,
I may have a bug for Mod_Callcenter but I wanted to see if anyone else might notice a setup issue before I send this on to Jira. I recently launched a production callcenter system for our company. We are currently beta testing the system with a small subset of our callers and we have noticed an issue where every so often (IE. Intermittent issue) when a caller arrives in queue and the queue offers the call to the agent, the offer happens twice.
What gets worse is that once the agent answers one of the calls the other call continues to attempt to reach the agent even while they are talking to the person they are receiving the second call for. When the call times out we get a "NO ANSWER" and then the callcenter system attempts the call again, and again, and again until the agent is done with the caller.
Even more interesting is that the agent state and member state keep changing to reflect the state of the second calling thread that keeps trying even though the caller is actually speaking to the agent.
Here is a log from the freeswitch events. This was taken using log level 5 in the cli. Lines in BLUE are cli statements I am recording when events are fired that I care about. I am using Mod_managed to listen to events and update information in a company database. Lines in RED are notes about the logs.
2011-11-04 15:44:06.340969 [ALERT] switch_cpp.cpp:1223 PsiQueueEventConsumer - CallLogId Not Detected, Attempting to Create New :: Unavailable(2406740599) calling cc+
--- A CALLER JUST JOINED THE QUEUE ---
2011-11-04 15:44:45.160968 [NOTICE] switch_channel.c:915 New Channel sofia/external/sip:4503@97.75.182.83:59868 [35e23ce8-072e-11e1-a636-2d222f47338b]
2011-11-04 15:44:45.160968 [NOTICE] switch_channel.c:915 New Channel sofia/external/sip:4503@97.75.182.83:59868 [35e24e68-072e-11e1-a63a-2d222f47338b]
--- NOTICE HOW 2 CHANNELS WERE INITIATED TO THE SAME EXTENSION/AGENT ---
--- AGENT STATE: 'Receiving' ---
--- THE AGENT ANSWERED ONLY ONE OF THE CALLS ---
--- AGENT STATE: 'In A Queue Call' ---
2011-11-04 15:44:55.000947 [NOTICE] switch_ivr_originate.c:3167 Hangup sofia/external/sip:4503@97.75.182.83:59868 [CS_CONSUME_MEDIA] [NO_ANSWER]
2011-11-04 15:44:55.000947 [NOTICE] switch_ivr_originate.c:2459 Cannot create outgoing channel of type [user] cause: [NO_ANSWER]
--- THE SECOND CHANNEL JUST TIMED OUT AND FLAGGED THE CALL AS A "NO ANSWER" ---
2011-11-04 15:44:55.000947 [NOTICE] switch_channel.c:915 New Channel sofia/external/sip:4503@97.75.182.83:59868 [3bc0c008-072e-11e1-a642-2d222f47338b]
--- AGENT STATE: 'Receiving' ---
--- SECOND CHANNEL ATTEMPTS AGAIN TO REACH THE AGENT, THE AGENT IS ALREADY TALKING TO THE CALLER ---
2011-11-04 15:45:05.000941 [NOTICE] switch_ivr_originate.c:3167 Hangup sofia/external/sip:4503@97.75.182.83:59868 [CS_CONSUME_MEDIA] [NO_ANSWER]
2011-11-04 15:45:05.000941 [NOTICE] switch_ivr_originate.c:2459 Cannot create outgoing channel of type [user] cause: [NO_ANSWER]
--- NO ANSWER TIMEOUT REPEATS ---
2011-11-04 15:45:05.060918 [NOTICE] switch_channel.c:915 New Channel sofia/external/sip:4503@97.75.182.83:59868 [41be0a9c-072e-11e1-a647-2d222f47338b]
--- AGENT STATE: 'Receiving' ---
2011-11-04 15:45:15.001026 [NOTICE] switch_ivr_originate.c:3167 Hangup sofia/external/sip:4503@97.75.182.83:59868 [CS_CONSUME_MEDIA] [NO_ANSWER]
2011-11-04 15:45:15.001026 [NOTICE] switch_ivr_originate.c:2459 Cannot create outgoing channel of type [user] cause: [NO_ANSWER]
--- LOOPS CONTINUALLY FOR 7 MINUTES ---
....
--- TRIES AGAIN ---
2011-11-04 15:52:15.040968 [NOTICE] switch_channel.c:915 New Channel sofia/external/sip:4503@97.75.182.83:59868 [4208943a-072f-11e1-a72a-2d222f47338b]
--- AGENT STATE: 'Receiving' ---
2011-11-04 15:52:25.000919 [NOTICE] switch_ivr_originate.c:3167 Hangup sofia/external/sip:4503@97.75.182.83:59868 [CS_CONSUME_MEDIA] [NO_ANSWER]
2011-11-04 15:52:25.000919 [NOTICE] switch_ivr_originate.c:2459 Cannot create outgoing channel of type [user] cause: [NO_ANSWER]
2011-11-04 15:52:28.140959 [NOTICE] switch_ivr_bridge.c:658 Hangup sofia/external/sip:4503@97.75.182.83:59868 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
--- AGENT ACTUALLY HANGS UP ON THE REAL CALL ---
--- AGENT STATE: 'Waiting' ---
--- THE LOOP IS ENDED BECAUSE THE MEMBER IS NO LONGER IN THE SYSTEM ---
While the agent state keeps changing the agent is actually in a call with the caller this entire time. Events are firing every 10 seconds informing me this agent had a "No Answer" on an inbound call when they are actually talking to the caller.
Here are some settings in case you want to know:
freeswitch@internal> callcenter_config queue list
name|strategy|moh_sound|time_base_score|tier_rules_apply|tier_rule_wait_second|tier_rule_wait_multiply_level|tier_rule_no_agent_no_wait|discard_abandoned_after|abandoned_resume_allowed|max_wait_time|max_wait_time_with_no_agent|max_wait_time_with_no_agent_time_reached|record_template
callcenter@sip.<hidden>.com|longest-idle-agent|local_stream://moh|system|false|300|true|false|60|false|0|0|5|/usr/local/freeswitch/recordings/${strftime(%Y-%m-%d-%H-%M-%S)}.${destination_number}.${caller_id_number}.${uuid}.wav
freeswitch@internal> callcenter_config agent list
name|system|uuid|type|contact|status|state|max_no_answer|wrap_up_time|reject_delay_time|busy_delay_time|no_answer_delay_time|last_bridge_start|last_bridge_end|last_offered_call|last_status_change|no_answer_count|calls_answered|talk_time|ready_time
7003@sip.<hidden>.com|single_box|6d3dabc4-0732-11e1-a7c6-2d222f47338b|callback|[call_timeout=10]user/4513@sip.<hidden>.com|Available|In a queue call|0|30|0|0|0|1320444899|1320444795|1320444896|1320443529|0|4|1129|0
7004@sip.<hidden>.com|single_box||callback|[call_timeout=10]user/4503@sip.<hidden>.com|Available|Waiting|0|30|0|0|0|1320445006|1320445099|1320445000|1320434600|0|24|4254|0
And here are the queue settings in XML. Same as above but easier to read.
<queues>
<queue name="callcenter@sip.<hidden>.com">
<param name="strategy" value="longest-idle-agent"/>
<param name="moh-sound" value="$${hold_music}"/>
<param name="record-template" value="$${base_dir}/recordings/${strftime(%Y-%m-%d-%H-%M-%S)}.${destination_number}.${caller_id_number}.${uuid}.wav"/>
<param name="time-base-score" value="system"/>
<param name="max-wait-time" value="0"/>
<param name="max-wait-time-with-no-agent" value="0"/>
<param name="max-wait-time-with-no-agent-time-reached" value="5"/>
<param name="tier-rules-apply" value="false"/>
<param name="tier-rule-wait-second" value="300"/>
<param name="tier-rule-wait-multiply-level" value="true"/>
<param name="tier-rule-no-agent-no-wait" value="false"/>
<param name="discard-abandoned-after" value="60"/>
<param name="abandoned-resume-allowed" value="false"/>
</queue>
</queues>
So to summarize, most calls work exactly as expected, but a percentage of our total call volume is currently having this issue. We are taking around 200 calls per day at the moment but we plan to take many more in the coming month. We have another system with an IVR in front of this and it only hands callers of a particular ivr option to this server.
I should also note that we are running Dual Quad Core Intel Xeon's, 8GB DDR2, Suse 11.4 - x86_64, Mono 1.8.2. We are also testing 3 Polycom 450's and 5 X-Lite SoftPhones with our agents.
Any suggestions or help would be appreciated.
Thanks!
Ryan H