Calls stuck in queue despite members waiting

davidwave · May 22, 2020, 4:29pm

Hi,

I’m having a problem where callers are left sitting in a queue for a long time (minutes!) despite there being members available to take the call. I’m using a ringall queue with no fancy priority, pausing, etc. All of the queue members are connected via a SIP connection to an external telco, which calls their mobile phone. When the member isn’t working they keep their phone turned off or in aeroplane mode to ignore calls.

We’re using Asterisk 16.4.0 inside a Debian docker container.

We’d been using this setup for ~6 months without problems, but call volume has increased recently so maybe it could be related to that? Or it could be that people only notice the issue with high call volumes.

Does anyone have any idea why this could be happening? Is there anything that I can check to help debug further?

I see a fair number of “The ‘stasis/p:channel:all-0002dc5c’ task processor queue reached 500 scheduled tasks again” warnings, could that be related?

Here’s our queue.conf

[general]
persistentmembers = yes
monitor-type = MixMonitor

[support-general]
music=wavesupport-queue
strategy=ringall
setinterfacevar=yes
setqueuevar=yes
setqueueentryvar=yes
servicelevel=10
timeout=15 ; Keep ringing for 15s. After 15s it will hangup and start ringing again.
retry=2

member => Local/adjaratoufatou@reps
member => Local/aidag@reps
member => Local/alaino@reps
... etc

And here are the relevant extensions:

[reps]
exten => telco_dial,1,NoOp(),
  ; Attempt to dial the rep's mobile number with the incoming caller id and run on-rep-pickup when the rep answers
  same => n,Dial(PJSIP/${ARG1}@telco-out,60,b(set-pai-header^custom^1(${THEIR_CALLERID}))U(on-rep-pickup^${ARG1}^${ARG2}))
  same => n,Return()

exten => adjaratoufatou,1,GoSub(reps,telco_dial,1(+[PHONE NUMBER],adjaratoufatou))
... etc

Here’s the output of queue show (shortly after a queue reload, which is why many members haven’t taken any calls):

support-general has 18 calls (max unlimited) in 'ringall' strategy (158s holdtime, 0s talktime), W:0, C:31, A:77, SL:0.0%, SL2:8.3% within 10s
   Members: 
      Local/assthiam@reps (ringinuse enabled) (In use) has taken no calls yet
      Local/augustin@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/elisabethmendy@reps (ringinuse enabled) (Not in use) has taken 3 calls (last was 124 secs ago)
      Local/elise@reps (ringinuse enabled) (Not in use) has taken 3 calls (last was 108 secs ago)
      Local/clemencediouf@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/maremesoda@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/mohameds@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/souleye@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/mamadoukama@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/bampoky@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/mariabilo@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/mariama@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/mariamasene@reps (ringinuse enabled) (Not in use) has taken 1 calls (last was 9 secs ago)
      Local/mariegomis@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/marietherese@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/mameyande@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/simeonciss@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/aidag@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/jenniferh@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/papalaobe@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/awathiam@reps (ringinuse enabled) (Not in use) has taken 2 calls (last was 52 secs ago)
      Local/ernestniane@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/florenceaffoibassene@reps (ringinuse enabled) (Not in use) has taken 4 calls (last was 48 secs ago)
      Local/papeseck@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/philomenegomis@reps (ringinuse enabled) (Not in use) has taken 5 calls (last was 64 secs ago)
      Local/elimanesall@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/abdelkader@reps (ringinuse enabled) (Invalid) has taken no calls yet
      Local/helene@reps (ringinuse enabled) (Not in use) has taken 2 calls (last was 161 secs ago)
      Local/luc@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/hamad@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/maimounadiakhate@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/adjaratoufatou@reps (ringinuse enabled) (Not in use) has taken 1 calls (last was 188 secs ago)
      Local/annekeita@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/cherifcoly@reps (ringinuse enabled) (Not in use) has taken 4 calls (last was 3 secs ago)
      Local/mor@reps (ringinuse enabled) (Not in use) has taken 2 calls (last was 118 secs ago)
      Local/yaya@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/alaino@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/bousso@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/margaritediouf@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/moussa@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/moussadiouf@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/amsatou@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/dionsobadiedhiou@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/estherdasylva@reps (ringinuse enabled) (Not in use) has taken 2 calls (last was 236 secs ago)
      Local/mouhamadoucissokho@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/ndeyedioallo@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/josephine@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/josephndiaye@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/khadidiatou@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/neneyobadiallo@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/binetou@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/christinediouf@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/laurent@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/odile@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/dieudonnediouf@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/virginie@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/bintoutoure@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/dieynabadiong@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/noel@reps (ringinuse enabled) (Not in use) has taken no calls yet
      Local/amadoucissokho@reps (ringinuse enabled) (Not in use) has taken 1 calls (last was 14 secs ago)
      Local/benedicte@reps (ringinuse enabled) (Not in use) has taken no calls yet
   Callers: 
      1. PJSIP/telco-out-0002a4b9 (wait: 2:51, prio: 0)
      2. PJSIP/telco-out-0002a4bb (wait: 2:50, prio: 0)
      3. PJSIP/telco-out-0002a5b7 (wait: 2:23, prio: 0)
      4. PJSIP/telco-out-0002a632 (wait: 2:13, prio: 0)
      5. PJSIP/telco-out-0002a633 (wait: 2:10, prio: 0)
      6. PJSIP/telco-out-0002a6ed (wait: 1:53, prio: 0)
      7. PJSIP/telco-out-0002a864 (wait: 1:20, prio: 0)
      8. PJSIP/telco-out-0002a867 (wait: 1:18, prio: 0)
      9. PJSIP/telco-out-0002a8a7 (wait: 1:11, prio: 0)
      10. PJSIP/telco-out-0002a8e4 (wait: 1:06, prio: 0)
      11. PJSIP/telco-out-0002a922 (wait: 1:02, prio: 0)
      12. PJSIP/telco-out-0002a924 (wait: 1:01, prio: 0)
      13. PJSIP/telco-out-0002a926 (wait: 0:59, prio: 0)
      14. PJSIP/telco-out-0002a964 (wait: 0:54, prio: 0)
      15. PJSIP/telco-out-0002ab14 (wait: 0:12, prio: 0)
      16. PJSIP/telco-out-0002ab17 (wait: 0:08, prio: 0)
      17. PJSIP/telco-out-0002ab55 (wait: 0:04, prio: 0)
      18. PJSIP/telco-out-0002ab92 (wait: 0:00, prio: 0)

Here’s an example of the problem (with phone numbers removed), note the 2 minute gap where nothing happens just after the music on hold starts.

2020-05-22 16:58:25.537 Executing [200600@wavesupport:1] NoOp("PJSIP/telco-out-00032e90", "") in new stack
2020-05-22 16:58:25.537 Executing [200600@wavesupport:2] Gosub("PJSIP/telco-out-00032e90", "on-start,s,1(PHONE_NUM)") in new stack
2020-05-22 16:58:25.538 Executing [s@on-start:1] NoOp("PJSIP/telco-out-00032e90", "") in new stack
2020-05-22 16:58:25.538 Executing [s@on-start:2] Gosub("PJSIP/telco-out-00032e90", "set-wave-call-id,s,1") in new stack
2020-05-22 16:58:25.539 Executing [s@set-wave-call-id:1] NoOp("PJSIP/telco-out-00032e90", "") in new stack
2020-05-22 16:58:25.632 Executing [s@set-wave-call-id:2] Set("PJSIP/telco-out-00032e90", "__CDR_WAVE_CALLID=PC_bb723d7bade042b0b7699022dc6b2336") in new stack
2020-05-22 16:58:25.632 Executing [s@set-wave-call-id:3] Return("PJSIP/telco-out-00032e90", "") in new stack
2020-05-22 16:58:25.632 Executing [s@on-start:3] Set("PJSIP/telco-out-00032e90", "__CDR_USER_CHANNEL=PJSIP/telco-out-00032e90") in new stack
2020-05-22 16:58:25.632 Executing [s@on-start:4] Set("PJSIP/telco-out-00032e90", "CHANNEL(hangup_handler_push)=onhangup,s,1") in new stack
2020-05-22 16:58:25.633 Executing [s@on-start:5] Gosub("PJSIP/telco-out-00032e90", "set-their-number,PHONE_NUM,1") in new stack
2020-05-22 16:58:25.633 Executing [PHONE_NUM@set-their-number:1] NoOp("PJSIP/telco-out-00032e90", "") in new stack
2020-05-22 16:58:25.633 Executing [PHONE_NUM@set-their-number:2] Set("PJSIP/telco-out-00032e90", "__THEIR_CALLERID=+PHONENUM") in new stack
2020-05-22 16:58:25.633 Executing [PHONE_NUM@set-their-number:3] Set("PJSIP/telco-out-00032e90", "__CDR_THEIR_NUMBER=+PHONENUM") in new stack
2020-05-22 16:58:25.633 Executing [PHONE_NUM@set-their-number:4] Return("PJSIP/telco-out-00032e90", "") in new stack
2020-05-22 16:58:25.633 Executing [s@on-start:6] Gosub("PJSIP/telco-out-00032e90", "set-cdr-started-now,s,1") in new stack
2020-05-22 16:58:25.633 Executing [s@set-cdr-started-now:1] NoOp("PJSIP/telco-out-00032e90", "") in new stack
2020-05-22 16:58:25.633 Executing [s@set-cdr-started-now:2] Set("PJSIP/telco-out-00032e90", "__CDR_WHEN_STARTED="2020-05-22 16:58:25"") in new stack
2020-05-22 16:58:25.633 Executing [s@set-cdr-started-now:3] Return("PJSIP/telco-out-00032e90", "") in new stack
2020-05-22 16:58:25.634 Executing [s@on-start:7] Return("PJSIP/telco-out-00032e90", "") in new stack
2020-05-22 16:58:25.634 Executing [200600@wavesupport:3] Log("PJSIP/telco-out-00032e90", "NOTICE,"[PC_bb723d7bade042b0b7699022dc6b2336] Incoming call from +PHONENUM"") in new stack
2020-05-22 16:58:25.634 "[PC_bb723d7bade042b0b7699022dc6b2336] Incoming call from +PHONENUM"
2020-05-22 16:58:25.634 Executing [200600@wavesupport:4] Answer("PJSIP/telco-out-00032e90", "") in new stack
2020-05-22 16:58:25.846 0x7fdb0c00f1e0 -- Strict RTP switching to RTP target address 10.5.64.9:49578 as source
2020-05-22 16:58:25.846 Executing [200600@wavesupport:5] GotoIfTime("PJSIP/telco-out-00032e90", "22:00-08:00,mon-sat,*,*?out-of-office") in new stack
2020-05-22 16:58:25.846 Executing [200600@wavesupport:6] GotoIfTime("PJSIP/telco-out-00032e90", "21:00-09:00,sun,*,*?out-of-office") in new stack
2020-05-22 16:58:25.846 Executing [200600@wavesupport:7] Set("PJSIP/telco-out-00032e90", "__CDR_IS_ROBOCALL=false") in new stack
2020-05-22 16:58:25.846 Executing [200600@wavesupport:8] Gosub("PJSIP/telco-out-00032e90", "gql,create_incoming,1") in new stack
2020-05-22 16:58:25.847 Executing [create_incoming@gql:1] NoOp("PJSIP/telco-out-00032e90", "") in new stack
2020-05-22 16:58:25.847 Executing [create_incoming@gql:2] Set("PJSIP/telco-out-00032e90", "VARIABLES={"callId": "PC_bb723d7bade042b0b7699022dc6b2336", "isRobocall": false, "phoneServer": "asterisk-sn", "whenStarted": "2020-05-22 16:58:25", "theirTelnum": "+PHONENUM"}") in new stack
2020-05-22 16:58:25.847 Executing [create_incoming@gql:3] System("PJSIP/telco-out-00032e90", "curl -s -S -w '\n' "https://ng.mmapp.wave.com/a/callcenter_graphql" -X POST -H "Authorization: Bearer XXXXX" -H "Content-Type: application/json" -d '{"query": "mutation CreateIncomingCallRecord($callId: ID!, $isRobocall: Boolean!, $phoneServer: String!, $whenStarted: DateTime!, $theirTelnum: String!) { createIncomingCallRecord(callId: $callId, isRobocall: $isRobocall, phoneServer: $phoneServer, whenStarted: $whenStarted, theirTelnum: $theirTelnum) { phoneCallRecord { id } } }", "variables": {"callId": "PC_bb723d7bade042b0b7699022dc6b2336", "isRobocall": false, "phoneServer": "asterisk-sn", "whenStarted": "2020-05-22 16:58:25", "theirTelnum": "+PHONENUM"}}' &") in new stack
2020-05-22 16:58:25.904 Executing [create_incoming@gql:4] Return("PJSIP/telco-out-00032e90", "") in new stack
2020-05-22 16:58:25.904 Executing [200600@wavesupport:9] Queue("PJSIP/telco-out-00032e90", "support-general") in new stack
2020-05-22 16:58:25.905 Started music on hold, class 'wavesupport-queue', on channel 'PJSIP/telco-out-00032e90'
2020-05-22 16:58:30.845 0x7fdb0c00f1e0 -- Strict RTP learning complete - Locking on source address 10.5.64.9:49578
2020-05-22 17:00:04.582 Stopped music on hold on PJSIP/telco-out-00032e90
2020-05-22 17:00:04.583 Spawn extension (wavesupport, 200600, 9) exited non-zero on 'PJSIP/telco-out-00032e90'
2020-05-22 17:00:04.583 PJSIP/telco-out-00032e90 Internal Gosub(onhangup,s,1) start
2020-05-22 17:00:04.583 Executing [s@onhangup:1] NoOp("PJSIP/telco-out-00032e90", "") in new stack
2020-05-22 17:00:04.583 Executing [s@onhangup:2] Gosub("PJSIP/telco-out-00032e90", "set-cdr-terminated-now,s,1") in new stack
2020-05-22 17:00:04.583 Executing [s@set-cdr-terminated-now:1] NoOp("PJSIP/telco-out-00032e90", "") in new stack
2020-05-22 17:00:04.583 Executing [s@set-cdr-terminated-now:2] Set("PJSIP/telco-out-00032e90", "__CDR_WHEN_TERMINATED="2020-05-22 17:00:04"") in new stack
2020-05-22 17:00:04.583 Executing [s@set-cdr-terminated-now:3] Return("PJSIP/telco-out-00032e90", "") in new stack
2020-05-22 17:00:04.645 Executing [s@onhangup:3] Set("PJSIP/telco-out-00032e90", "__CDR_WHO_TERMINATED=US") in new stack
2020-05-22 17:00:04.645 Executing [s@onhangup:4] Set("PJSIP/telco-out-00032e90", "__CDR_TERMINATION_REASON=AST/16") in new stack
2020-05-22 17:00:04.645 Executing [s@onhangup:5] Gosub("PJSIP/telco-out-00032e90", "gql,terminate,1") in new stack
2020-05-22 17:00:04.646 Executing [terminate@gql:1] NoOp("PJSIP/telco-out-00032e90", "") in new stack
2020-05-22 17:00:04.646 Executing [terminate@gql:2] Set("PJSIP/telco-out-00032e90", "VARIABLES={"callId": "PC_bb723d7bade042b0b7699022dc6b2336", "whenTerminated": "2020-05-22 17:00:04", "whoTerminated": "US", "terminationReason": "AST/16"}") in new stack
2020-05-22 17:00:04.646 Executing [terminate@gql:3] System("PJSIP/telco-out-00032e90", "curl -s -S -w '\n' "https://ng.mmapp.wave.com/a/callcenter_graphql" -X POST -H "Authorization: Bearer XXXXX" -H "Content-Type: application/json" -d '{"query": "mutation TerminateCallRecord($callId: ID!, $whenTerminated: DateTime!, $whoTerminated: PhoneCallActor!, $terminationReason: String) { terminateCallRecord(callId: $callId, whenTerminated: $whenTerminated, whoTerminated: $whoTerminated, terminationReason: $terminationReason) { phoneCallRecord { id } } }", "variables": {"callId": "PC_bb723d7bade042b0b7699022dc6b2336", "whenTerminated": "2020-05-22 17:00:04", "whoTerminated": "US", "terminationReason": "AST/16"}}' &") in new stack
2020-05-22 17:00:04.703 Executing [terminate@gql:4] Return("PJSIP/telco-out-00032e90", "") in new stack
2020-05-22 17:00:04.703 Executing [s@onhangup:6] Log("PJSIP/telco-out-00032e90", "NOTICE, "+PHONENUM hung up."") in new stack
2020-05-22 17:00:04.703  "+PHONENUM hung up."
2020-05-22 17:00:04.703 Executing [s@onhangup:7] Return("PJSIP/telco-out-00032e90", "") in new stack
2020-05-22 17:00:04.704 Spawn extension (wavesupport, 200600, 9) exited non-zero on 'PJSIP/telco-out-00032e90'
2020-05-22 17:00:04.704 PJSIP/telco-out-00032e90 Internal Gosub(onhangup,s,1) complete GOSUB_RETVAL=

david551 · May 22, 2020, 5:30pm

If you phone an agent’s mobile directly, preferably from another mobile, is the call rejected immediately, or is there a voice message or voicemail offer?

Do you have an agent that rings out (or even just one agent that doesn’t return busy immediately, as all agents available at the start of a ringing cycle will need to reject the call, before another cycle can start.

Asterisk is going to consider the unpaused but unreachable agents as being able to take calls, so will offer calls from down the queue to them. Because calls look up agents, rather than agents lookup calls, a call from down the queue may grab an agent that has just become free, in preference to one nearer the top of the queue.

(I’ve not really analyzed this for ringall, but, normally, as many calls at the head of the queue are eligible to be connected to ring an agent as there are free agents at the time. Your system may be misleading Asterisk into thinking more agents are free than is actually the case, as they will only be discovered to be busy when a call is attempted.)

Basically, the agents need to pause or be removed, before going offline. Your use of agents that aren’t local to Asterisk, means that Asterisk is unaware that they offline without actually calling them.

davidwave · May 22, 2020, 6:03pm

Hi, thanks for the suggestion. I just tried removing all of the agents who are not currently active and it didn’t help, so I guess that’s not the issue (we have had issues like that in the past though, and at some point we need to set up pausing when going offiline).

Do you have any other ideas for things I could look into?

system · June 21, 2020, 6:04pm

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.