Incoming calls generate single-ring calls randomly

[trymes]

I am struggling to track down a problem we have been experiencing here on our system running Trixbox 2.2 and QM 1.4.4. On a seemingly random basis, certain calls will not be passed through to an agent as normally happens. Most calls work just fine. Call comes in, placed in queue, sent to an agent, agent answers phone, all is good. However, some calls come in, get placed in the queue, and then bounce from agent to agent ringing only once before it goes to the next agent. Agents are not able to pick these calls up, even if they are really fast (ie: they pick it up while it is still ringing). We had one last week that bounced around like this for 4:44 (four minutes, 44 seconds) before being sent to an agent properly. Of course, due to Asterisk 1.2's lack of an atuofill feature, (ie: only one call is handled at a time, all other calls pile up behind it) this causes all calls to wait for longer until the problem call is finally answered.

Is this something that has been seen before? This server was originally set up a while back, and the instructions I used in the past had me add an entry for the queue to the Queues.conf file, so that file looks like this:

[general]
;
; Global settings for call queues

persistentmembers=yes

;   (none exist currently)
;
; Note that a timeout to fail out of a queue may be passed as part of applicati$
; from extensions.conf:
; Queue(queuename|[options]|[optionalurl]|[announceoverride]|[timeout])
; example: Queue(dave|t|||45)

[default]
;
; Default settings for queues (currently unused)
;

#include queues_custom.conf
#include queues_additional.conf

[400]
announce-frequency=0
timeout=25
strategy=rrmemory
retry=1
queue-youarenext=
queue-thereare=
queue-thankyou=queue-thankyou
queue-callswaiting=
music=default
monitor-join=yes
monitor-format=wav49
maxlen=0
leavewhenempty=no
joinempty=Yes
eventwhencalled=no
eventmemberstatus=no
context=
announce-holdtime=no
wrapuptime=35

member=Agent/100,1
member=Agent/101,1

and so on...

This entry in queues.conf is in addition to the entry made via FreePBX, which shows up in queues_additional.conf. Also, I have two custom contexts in from-internal-custom to avoid having to punch in an agent code when logging in (this is instead of the simpler one number to dial example given in the QM docs):

[from-internal-custom]
exten => *98,1,Answer()
exten => *98,n,Wait(0.25)
exten => *98,n,AgentCallBackLogin(${CALLERID(num)}||${CALLERID(num)}@from-inter$
exten => *98,n,Hangup()

exten => *99,1,Answer()
;exten => *99,n,Wait(0.5)
exten => *99,n,System(asterisk -rx "agent logoff Agent/${CALLERID(num)}")
exten => *99,n,Playback(agent-loggedoff)
exten => *99,n,Hangup()

Any help or insight would be appreciated.

Tom

[QueueMetrics]

Do you have a log of what happened with that call? It would be interesting to see what went wrong. Maybe it's just a known bug in * (QM has no control of the call dispatch logic, just shows what is going on).
 

[trymes]

This is definitely an asterisk problem; I know that QM has no effect on the call flow. I posted here because I thought that maybe the custom setup that QM recommends in the setup docs might be to blame.

I'll try to look up the CDRs for one of these calls. What other info would be useful?

Tom

[trymes]

From QM, by clicking on the call details, I get this:

Code: [Select]

Asterisk Call ID:      1216217403.21894
Date and time:    16/07/2008 - 10:10:10
Caller ID:   
Handled by:    agent/103
Duration:    146 sec.
Waiting time:    284 sec.
Original position    # 3
Disconnection cause:    Caller disconnected
Transferred to:   
URL:   
Status code:   
Srv   
Sound files:
- q400-20080716-101005-1216217403.21894.WAV
I haven't had much luck deciphering the CDRs from Freepbx or Trixbox, and so any help providing some useful information would be appreciated.

Tom

[trymes]

I was able to pull this from Master.cdr:

Code: [Select]

6038273245 400 ext-queues "WEBER,STEVE &AL" <6038273245> Zap/7-1 Agent/135 Queue 400|t|| 7/10/08 10:18 7/10/08 10:18 7/10/08 10:25 409 409 ANSWERED
6038273245 270 from-internal "WEBER,STEVE &AL" <6038273245> Local/270@from-internal-3b41,2 SIP/270-08bd8978 ResetCDR w 7/10/08 10:18 7/10/08 10:18 0 0 BUSY
6038273245 250 from-internal "WEBER,STEVE &AL" <6038273245> Local/250@from-internal-91c0,2 SIP/250-08bd8978 ResetCDR w 7/10/08 10:18 7/10/08 10:18 1 0 BUSY
6038273245 270 from-internal "WEBER,STEVE &AL" <6038273245> Local/270@from-internal-b7fa,2 SIP/270-08bd8978 ResetCDR w 7/10/08 10:18 7/10/08 10:18 0 0 BUSY
6038273245 250 from-internal "WEBER,STEVE &AL" <6038273245> Local/250@from-internal-2198,2 SIP/250-08bd8978 ResetCDR w 7/10/08 10:18 7/10/08 10:18 1 0 BUSY
6038273245 270 from-internal "WEBER,STEVE &AL" <6038273245> Local/270@from-internal-8d92,2 SIP/270-08bd8978 ResetCDR w 7/10/08 10:18 7/10/08 10:18 0 0 BUSY
6038273245 250 from-internal "WEBER,STEVE &AL" <6038273245> Local/250@from-internal-9af3,2 SIP/250-08bd8978 ResetCDR w 7/10/08 10:18 7/10/08 10:18 1 0 BUSY
6038273245 270 from-internal "WEBER,STEVE &AL" <6038273245> Local/270@from-internal-89a0,2 SIP/270-08bd8978 ResetCDR w 7/10/08 10:18 7/10/08 10:18 1 0 BUSY
6038273245 250 from-internal "WEBER,STEVE &AL" <6038273245> Local/250@from-internal-1b4e,2 SIP/250-08bd8978 ResetCDR w 7/10/08 10:18 7/10/08 10:18 0 0 BUSY
6038273245 270 from-internal "WEBER,STEVE &AL" <6038273245> Local/270@from-internal-f5bb,2 SIP/270-08bd8978 ResetCDR w 7/10/08 10:18 7/10/08 10:18 1 0 BUSY
6038273245 250 from-internal "WEBER,STEVE &AL" <6038273245> Local/250@from-internal-fdba,2 SIP/250-08bd8978 ResetCDR w 7/10/08 10:18 7/10/08 10:18 0 0 BUSY
6038273245 270 from-internal "WEBER,STEVE &AL" <6038273245> Local/270@from-internal-528f,2 SIP/270-08bd8978 ResetCDR w 7/10/08 10:19 7/10/08 10:19 1 0 BUSY
6038273245 250 from-internal "WEBER,STEVE &AL" <6038273245> Local/250@from-internal-bf24,2 SIP/250-08bd8978 ResetCDR w 7/10/08 10:19 7/10/08 10:19 0 0 BUSY
6038273245 270 from-internal "WEBER,STEVE &AL" <6038273245> Local/270@from-internal-6767,2 SIP/270-08bd8978 ResetCDR w 7/10/08 10:19 7/10/08 10:19 1 0 BUSY
6038273245 250 from-internal "WEBER,STEVE &AL" <6038273245> Local/250@from-internal-fb6b,2 SIP/250-08bd8978 ResetCDR w 7/10/08 10:19 7/10/08 10:19 0 0 BUSY
6038273245 270 from-internal "WEBER,STEVE &AL" <6038273245> Local/270@from-internal-4d2f,2 SIP/270-08bd8978 ResetCDR w 7/10/08 10:19 7/10/08 10:19 1 0 BUSY
6038273245 250 from-internal "WEBER,STEVE &AL" <6038273245> Local/250@from-internal-527a,2 SIP/250-08bd8978 ResetCDR w 7/10/08 10:19 7/10/08 10:19 0 0 BUSY
6038273245 270 from-internal "WEBER,STEVE &AL" <6038273245> Local/270@from-internal-53bd,2 SIP/270-08bd8978 ResetCDR w 7/10/08 10:19 7/10/08 10:19 0 0 BUSY
6038273245 250 from-internal "WEBER,STEVE &AL" <6038273245> Local/250@from-internal-9f54,2 SIP/250-08bd8978 ResetCDR w 7/10/08 10:19 7/10/08 10:19 0 0 BUSY
6038273245 270 from-internal "WEBER,STEVE &AL" <6038273245> Local/270@from-internal-db41,2 SIP/270-08bd8978 ResetCDR w 7/10/08 10:19 7/10/08 10:19 0 0 BUSY
6038273245 250 from-internal "WEBER,STEVE &AL" <6038273245> Local/250@from-internal-35e0,2 SIP/250-08bd8978 ResetCDR w 7/10/08 10:19 7/10/08 10:19 1 0 BUSY
6038273245 135 from-internal "WEBER,STEVE &AL" <6038273245> Local/135@from-internal-3594,2 SIP/135-08bd8978 Dial SIP/135|25|trwM(auto-blkvm) 7/10/08 10:19 7/10/08 10:19 7/10/08 10:19 6 0 ANSWERED
It seems that the system thinks the phones are busy, but they are not. Any thoughts on this?

Tom

PS: My apologies for the messy post...

[QueueMetrics]

Are you sure you are not experiencing an IP problem, like all phones going offline for a few seconds because the master switch resets?

[trymes]

I doubt it, because ongoing calls are not interrupted, and the phones indeed ring, but only once.

Tom

[QueueMetrics]

I would turn on the full detailed Asterisk log and go look into it at the timestamp the problem happens. Very likely you'll see something strange (do rotate it, it gets huge fast).

[trymes]

Where would this be set? Also, this reminds me, if qloaderd is reading queue_log, is it ok to rotate it so it doesn't get so big?

[QueueMetrics]

You can set this by editing the /etc/asterisk/logger.conf and uncommenting the line that says:

Code: [Select]

full => notice,warning,error,debug,verbose
This will create /var/log/asterisk/full - that file gets big fast, so you can rotate it. Do not rotate the queue_log instead.