Asterisk sending calls to busy queue agents even if it shouldn’t
I’m using Asterisk 18.17.0 with five queues and dynamic agents common to several queues.
This is the queues configuration:
[401]
announce-frequency=0
announce-holdtime=no
announce-position=no
autofill=yes
autopause=no
autopausebusy=no
autopausedelay=0
autopauseunavail=no
joinempty=yes
leavewhenempty=no
maxlen=25
memberdelay=0
min-announce-frequency=15
musicclass=default
penaltymemberslimit=0
periodic-announce-frequency=0
queue-callswaiting=silence/1
queue-thereare=silence/1
queue-youarenext=silence/1
reportholdtime=no
retry=5
ringinuse=yes
servicelevel=60
strategy=random
timeout=20
timeoutpriority=app
timeoutrestart=no
weight=9
wrapuptime=2
context=
[402]
announce-frequency=0
announce-holdtime=no
announce-position=no
autofill=yes
autopause=no
autopausebusy=no
autopausedelay=0
autopauseunavail=no
joinempty=yes
leavewhenempty=no
maxlen=25
memberdelay=0
min-announce-frequency=15
musicclass=default
penaltymemberslimit=0
periodic-announce-frequency=0
queue-callswaiting=silence/1
queue-thereare=silence/1
queue-youarenext=silence/1
reportholdtime=no
retry=5
ringinuse=yes
servicelevel=60
strategy=random
timeout=20
timeoutpriority=app
timeoutrestart=no
weight=8
wrapuptime=2
context=
[403]
announce-frequency=0
announce-holdtime=no
announce-position=no
autofill=yes
autopause=no
autopausebusy=no
autopausedelay=0
autopauseunavail=no
joinempty=yes
leavewhenempty=no
maxlen=20
memberdelay=0
min-announce-frequency=15
musicclass=default
penaltymemberslimit=0
periodic-announce-frequency=0
queue-callswaiting=silence/1
queue-thereare=silence/1
queue-youarenext=silence/1
reportholdtime=no
retry=5
ringinuse=yes
servicelevel=60
strategy=random
timeout=20
timeoutpriority=app
timeoutrestart=no
weight=10
wrapuptime=2
context=
[404]
announce-frequency=0
announce-holdtime=no
announce-position=no
autofill=yes
autopause=no
autopausebusy=no
autopausedelay=0
autopauseunavail=no
joinempty=yes
leavewhenempty=no
maxlen=20
memberdelay=0
min-announce-frequency=15
musicclass=default
penaltymemberslimit=0
periodic-announce-frequency=0
queue-callswaiting=silence/1
queue-thereare=silence/1
queue-youarenext=silence/1
reportholdtime=no
retry=5
ringinuse=yes
servicelevel=60
strategy=random
timeout=20
timeoutpriority=app
timeoutrestart=no
weight=10
wrapuptime=2
context=
[405]
announce-frequency=0
announce-holdtime=no
announce-position=no
autofill=yes
autopause=no
autopausebusy=no
autopausedelay=0
autopauseunavail=no
joinempty=yes
leavewhenempty=no
maxlen=25
memberdelay=0
min-announce-frequency=15
musicclass=default
penaltymemberslimit=0
periodic-announce-frequency=0
queue-callswaiting=silence/1
queue-thereare=silence/1
queue-youarenext=silence/1
reportholdtime=no
retry=5
ringinuse=yes
servicelevel=60
strategy=random
timeout=20
timeoutpriority=app
timeoutrestart=no
weight=10
wrapuptime=2
context=
The agents have Local interface in the queues and use hints for the state interface.
401 has 1 calls (max 25) in ‘random’ strategy (55s holdtime, 140s talktime), W:9, C:186, A:51, SL:64.5%, SL2:59.5% within 60s
Members:
Elisa (Local/234@from-queue/n from hint:234@ext-local) (ringinuse enabled) (dynamic) (In use) has taken 62 calls (last was 166 secs ago) (login was 12982 secs ago)
Giovanni (Local/233@from-queue/n from hint:233@ext-local) (ringinuse enabled) (dynamic) (paused was 12767 secs ago) (Not in use) has taken no calls yet (login was 12767 secs ago)
Michela (Local/263@from-queue/n from hint:263@ext-local) (ringinuse enabled) (dynamic) (in call) (In use) has taken no calls yet (login was 322 secs ago)
Aurora (Local/262@from-queue/n from hint:262@ext-local) (ringinuse enabled) (dynamic) (paused was 8417 secs ago) (Not in use) has taken no calls yet (login was 8417 secs ago)
Samanta (Local/259@from-queue/n from hint:259@ext-local) (ringinuse enabled) (dynamic) (Unavailable) has taken no calls yet (login was 45019 secs ago)
Agnese (Local/258@from-queue/n from hint:258@ext-local) (ringinuse enabled) (dynamic) (In use) has taken 57 calls (last was 83 secs ago) (login was 13317 secs ago)
Marta (Local/257@from-queue/n from hint:257@ext-local) (ringinuse enabled) (dynamic) (Not in use) has taken 41 calls (last was 14 secs ago) (login was 45019 secs ago)
Miriana (Local/223@from-queue/n from hint:223@ext-local) (ringinuse enabled) (dynamic) (In use) has taken 14 calls (last was 91 secs ago) (login was 2027 secs ago)
Valentina (Local/221@from-queue/n from hint:221@ext-local) (ringinuse enabled) (dynamic) (In use) has taken 42 calls (last was 85 secs ago) (login was 12976 secs ago)
Francesco (Local/255@from-queue/n from hint:255@ext-local) (ringinuse enabled) (dynamic) (In use) has taken 47 calls (last was 173 secs ago) (login was 12826 secs ago)
Valeria (Local/249@from-queue/n from hint:249@ext-local) (ringinuse enabled) (dynamic) (In use) has taken 51 calls (last was 272 secs ago) (login was 13326 secs ago)
Giada (Local/213@from-queue/n from hint:213@ext-local) (ringinuse enabled) (dynamic) (paused was 6244 secs ago) (Not in use) has taken no calls yet (login was 6244 secs ago)
Anna (Local/242@from-queue/n from hint:242@ext-local) (ringinuse enabled) (dynamic) (paused was 11520 secs ago) (Not in use) has taken no calls yet (login was 11520 secs ago)
Elisa (Local/207@from-queue/n from hint:207@ext-local) (ringinuse enabled) (dynamic) (In use) has taken no calls yet (login was 136 secs ago)
Elisa (Local/239@from-queue/n from hint:239@ext-local) (ringinuse enabled) (dynamic) (Ringing) has taken 51 calls (last was 10 secs ago) (login was 12894 secs ago)
Chiara (Local/235@from-queue/n from hint:235@ext-local) (ringinuse enabled) (dynamic) (paused was 1240 secs ago) (Not in use) has taken 1 calls (last was 1245 secs ago) (login was 1383 secs ago)
Callers:
1. PJSIP/TG200-00001df3 (wait: 0:03, prio: 0)
402 has 0 calls (max 25) in ‘random’ strategy (129s holdtime, 188s talktime), W:8, C:88, A:20, SL:45.5%, SL2:42.6% within 60s
Members:
Elisa (Local/234@from-queue/n from hint:234@ext-local) (ringinuse enabled) (dynamic) (In use) has taken 62 calls (last was 166 secs ago) (login was 12982 secs ago)
Samanta (Local/259@from-queue/n from hint:259@ext-local) (ringinuse enabled) (dynamic) (Unavailable) has taken no calls yet (login was 45019 secs ago)
Miriana (Local/223@from-queue/n from hint:223@ext-local) (ringinuse enabled) (dynamic) (in call) (In use) has taken 14 calls (last was 91 secs ago) (login was 2027 secs ago)
Valentina (Local/221@from-queue/n from hint:221@ext-local) (ringinuse enabled) (dynamic) (in call) (In use) has taken 42 calls (last was 85 secs ago) (login was 12976 secs ago)
Francesco (Local/255@from-queue/n from hint:255@ext-local) (ringinuse enabled) (dynamic) (In use) has taken 47 calls (last was 173 secs ago) (login was 12826 secs ago)
Anna (Local/242@from-queue/n from hint:242@ext-local) (ringinuse enabled) (dynamic) (paused was 11520 secs ago) (Not in use) has taken no calls yet (login was 11520 secs ago)
Elisa (Local/207@from-queue/n from hint:207@ext-local) (ringinuse enabled) (dynamic) (in call) (In use) has taken no calls yet (login was 136 secs ago)
Elisa (Local/239@from-queue/n from hint:239@ext-local) (ringinuse enabled) (dynamic) (Ringing) has taken 51 calls (last was 10 secs ago) (login was 12894 secs ago)
Chiara (Local/235@from-queue/n from hint:235@ext-local) (ringinuse enabled) (dynamic) (paused was 1240 secs ago) (Not in use) has taken 1 calls (last was 1245 secs ago) (login was 1383 secs ago)
No Callers
403 has 16 calls (max 20) in ‘random’ strategy (299s holdtime, 134s talktime), W:10, C:199, A:499, SL:3.0%, SL2:3.9% within 60s
Members:
Gabriele (Local/261@from-queue/n from hint:261@ext-local) (ringinuse enabled) (dynamic) (in call) (In use) has taken 8 calls (last was 263 secs ago) (login was 2013 secs ago)
Pierfrancesco (Local/226@from-queue/n from hint:226@ext-local) with penalty 3 (ringinuse enabled) (dynamic) (Ringing) has taken 4 calls (last was 183 secs ago) (login was 1740 secs ago)
Paolo (Local/218@from-queue/n from hint:218@ext-local) with penalty 3 (ringinuse enabled) (dynamic) (paused was 2011 secs ago) (Not in use) has taken 33 calls (last was 2013 secs ago) (login was 12660 secs ago)
Marco (Local/238@from-queue/n from hint:238@ext-local) (ringinuse enabled) (dynamic) (Ringing) has taken 29 calls (last was 229 secs ago) (login was 12690 secs ago)
Callers:
1. Local/403@cti-profile-12-00022416;2 (wait: 6:32, prio: 0)
2. PJSIP/TG200-00001d25 (wait: 4:52, prio: 0)
3. PJSIP/TG200-00001d29 (wait: 4:44, prio: 0)
4. PJSIP/TG200-00001d38 (wait: 4:09, prio: 0)
5. Local/403@cti-profile-12-00022c1d;2 (wait: 4:07, prio: 0)
6. PJSIP/TG200-00001d4c (wait: 4:04, prio: 0)
7. PJSIP/TG200-00001d77 (wait: 2:47, prio: 0)
8. PJSIP/TG200-00001d70 (wait: 2:46, prio: 0)
9. PJSIP/TG200-00001d91 (wait: 1:50, prio: 0)
10. PJSIP/TG200-00001d94 (wait: 1:38, prio: 0)
11. Local/403@cti-profile-12-000230d8;2 (wait: 1:24, prio: 0)
12. PJSIP/TG200-00001d9d (wait: 1:09, prio: 0)
13. PJSIP/TG200-00001d9c (wait: 0:57, prio: 0)
14. PJSIP/TG200-00001dc3 (wait: 0:53, prio: 0)
15. Local/403@cti-profile-11-00023223;2 (wait: 0:30, prio: 0)
16. PJSIP/TG200-00001dd8 (wait: 0:22, prio: 0)
404 has 3 calls (max 20) in ‘random’ strategy (26s holdtime, 99s talktime), W:10, C:279, A:12, SL:87.5%, SL2:86.6% within 60s
Members:
Letizia (Local/231@from-queue/n from hint:231@ext-local) (ringinuse enabled) (dynamic) (in call) (In use) has taken 78 calls (last was 248 secs ago) (login was 12841 secs ago)
Giulia (Local/222@from-queue/n from hint:222@ext-local) (ringinuse enabled) (dynamic) (in call) (In use) has taken 20 calls (last was 43 secs ago) (login was 5924 secs ago)
Marco (Local/215@from-queue/n from hint:215@ext-local) with penalty 3 (ringinuse enabled) (dynamic) (in call) (In use) has taken 47 calls (last was 30 secs ago) (login was 12829 secs ago)
Giulia (Local/246@from-queue/n from hint:246@ext-local) (ringinuse enabled) (dynamic) (Unavailable) has taken no calls yet (login was 45019 secs ago)
Antonio (Local/204@from-queue/n from hint:204@ext-local) with penalty 2 (ringinuse enabled) (dynamic) (paused was 11653 secs ago) (In use) has taken no calls yet (login was 11653 secs ago)
Alberto (Local/201@from-queue/n from hint:201@ext-local) with penalty 3 (ringinuse enabled) (dynamic) (in call) (In use) has taken 7 calls (last was 31 secs ago) (login was 695 secs ago)
Callers:
1. PJSIP/TG200-00001d92 (wait: 2:29, prio: 0)
2. PJSIP/TG200-00001dc5 (wait: 0:54, prio: 0)
3. PJSIP/TG200-00001de1 (wait: 0:04, prio: 0)
405 has 0 calls (max 25) in ‘random’ strategy (87s holdtime, 351s talktime), W:10, C:257, A:55, SL:59.5%, SL2:54.5% within 60s
Members:
Elisa (Local/234@from-queue/n from hint:234@ext-local) (ringinuse enabled) (dynamic) (in call) (In use) has taken 62 calls (last was 166 secs ago) (login was 12982 secs ago)
Giovanni (Local/233@from-queue/n from hint:233@ext-local) (ringinuse enabled) (dynamic) (paused was 12767 secs ago) (Not in use) has taken no calls yet (login was 12767 secs ago)
Michela (Local/263@from-queue/n from hint:263@ext-local) (ringinuse enabled) (dynamic) (In use) has taken no calls yet (login was 322 secs ago)
Samanta (Local/259@from-queue/n from hint:259@ext-local) (ringinuse enabled) (dynamic) (Unavailable) has taken no calls yet (login was 45019 secs ago)
Agnese (Local/258@from-queue/n from hint:258@ext-local) (ringinuse enabled) (dynamic) (In use) has taken 57 calls (last was 83 secs ago) (login was 13317 secs ago)
Marta (Local/257@from-queue/n from hint:257@ext-local) (ringinuse enabled) (dynamic) (Not in use) has taken 41 calls (last was 14 secs ago) (login was 45019 secs ago)
Miriana (Local/223@from-queue/n from hint:223@ext-local) (ringinuse enabled) (dynamic) (In use) has taken 14 calls (last was 91 secs ago) (login was 2027 secs ago)
Valentina (Local/221@from-queue/n from hint:221@ext-local) (ringinuse enabled) (dynamic) (In use) has taken 42 calls (last was 85 secs ago) (login was 12976 secs ago)
Francesco (Local/255@from-queue/n from hint:255@ext-local) (ringinuse enabled) (dynamic) (in call) (In use) has taken 47 calls (last was 173 secs ago) (login was 12826 secs ago)
Valeria (Local/249@from-queue/n from hint:249@ext-local) (ringinuse enabled) (dynamic) (in call) (In use) has taken 51 calls (last was 272 secs ago) (login was 13326 secs ago)
Anna (Local/242@from-queue/n from hint:242@ext-local) (ringinuse enabled) (dynamic) (paused was 11520 secs ago) (Not in use) has taken no calls yet (login was 11520 secs ago)
Elisa (Local/207@from-queue/n from hint:207@ext-local) (ringinuse enabled) (dynamic) (In use) has taken no calls yet (login was 136 secs ago)
Elisa (Local/239@from-queue/n from hint:239@ext-local) (ringinuse enabled) (dynamic) (Ringing) has taken 51 calls (last was 10 secs ago) (login was 12894 secs ago)
Chiara (Local/235@from-queue/n from hint:235@ext-local) (ringinuse enabled) (dynamic) (paused was 1240 secs ago) (Not in use) has taken 1 calls (last was 1245 secs ago) (login was 1383 secs ago)
No Callers
There is a load of ~60 concurrent calls sent to queues.
When a call enters the queue, it happens very often that the queue tries to contact agents who are already busy, and it happens many times per second. This is the Asterisk log of one of this attempts:
[2023-03-28 09:01:04] VERBOSE[5928][C-00000071] pbx.c: Executing [401@ext-queues:51] Queue(“PJSIP/TG200-00000076”, “401,tC,300,”) in new stack
[2023-03-28 09:01:04] VERBOSE[5928][C-00000071] res_musiconhold.c: Started music on hold, class ‘default’, on channel ‘PJSIP/TG200-00000076’
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [234@from-queue:1] Set(“Local/234@from-queue-00000006;2”, “QAGENT=234”) in new stack
[2023-03-28 09:01:04] VERBOSE[5928][C-00000071] app_queue.c: Called Local/234@from-queue/n
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [234@from-queue:2] Set(“Local/234@from-queue-00000006;2”, “__FROMQ=true”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [234@from-queue:3] GotoIf(“Local/234@from-queue-00000006;2”, “0?hangup”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [234@from-queue:4] GotoIf(“Local/234@from-queue-00000006;2”, “1?401,1:hangup”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx_builtins.c: Goto (from-queue,401,1)
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [401@from-queue:1] Goto(“Local/234@from-queue-00000006;2”, “from-queue-exten-only,234,1”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx_builtins.c: Goto (from-queue-exten-only,234,1)
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [234@from-queue-exten-only:1] GotoIf(“Local/234@from-queue-00000006;2”, “0?hangup”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [234@from-queue-exten-only:2] GotoIf(“Local/234@from-queue-00000006;2”, “0?from-queue-exten-only-x,234,1”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [234@from-queue-exten-only:3] Set(“Local/234@from-queue-00000006;2”, “RingGroupMethod=none”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [234@from-queue-exten-only:4] Set(“Local/234@from-queue-00000006;2”, “CHANNEL(language)=it”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [234@from-queue-exten-only:5] Set(“Local/234@from-queue-00000006;2”, “QDOPTS=”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [234@from-queue-exten-only:6] Set(“Local/234@from-queue-00000006;2”, “CDR(cnum)=XXXXXXXXXX”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [234@from-queue-exten-only:7] Set(“Local/234@from-queue-00000006;2”, “CDR(cnam)=”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [234@from-queue-exten-only:8] Set(“Local/234@from-queue-00000006;2”, “CDR(ccompany)=”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [234@from-queue-exten-only:9] Set(“Local/234@from-queue-00000006;2”, “CALLTYPE_OVERRIDE=external”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [234@from-queue-exten-only:10] ExecIf(“Local/234@from-queue-00000006;2”, “1?Set(FROMEXTEN=401)”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [234@from-queue-exten-only:11] Gosub(“Local/234@from-queue-00000006;2”, “sub-record-check,s,1(exten,234,)”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [s@sub-record-check:1] GotoIf(“Local/234@from-queue-00000006;2”, “3?initialized”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx_builtins.c: Goto (sub-record-check,s,10)
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [s@sub-record-check:10] NoOp(“Local/234@from-queue-00000006;2”, “Recordings initialized”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [s@sub-record-check:11] ExecIf(“Local/234@from-queue-00000006;2”, “1?Set(ARG3=dontcare)”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [s@sub-record-check:12] Set(“Local/234@from-queue-00000006;2”, “REC_POLICY_MODE_SAVE=”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [s@sub-record-check:13] ExecIf(“Local/234@from-queue-00000006;2”, “0?Set(REC_STATUS=NO)”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [s@sub-record-check:14] GotoIf(“Local/234@from-queue-00000006;2”, “5?checkaction”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx_builtins.c: Goto (sub-record-check,s,17)
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [s@sub-record-check:17] GotoIf(“Local/234@from-queue-00000006;2”, “1?sub-record-check,exten,1”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx_builtins.c: Goto (sub-record-check,exten,1)
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [exten@sub-record-check:1] NoOp(“Local/234@from-queue-00000006;2”, “Exten Recording Check between 401 and 234”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [exten@sub-record-check:2] Set(“Local/234@from-queue-00000006;2”, “CALLTYPE=external”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [exten@sub-record-check:3] ExecIf(“Local/234@from-queue-00000006;2”, “8?Set(CALLTYPE=external)”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [exten@sub-record-check:4] Set(“Local/234@from-queue-00000006;2”, “CALLEE=dontcare”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [exten@sub-record-check:5] ExecIf(“Local/234@from-queue-00000006;2”, “0?Set(CALLEE=dontcare)”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [exten@sub-record-check:6] GotoIf(“Local/234@from-queue-00000006;2”, “1?callee”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx_builtins.c: Goto (sub-record-check,exten,11)
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [exten@sub-record-check:11] Gosub(“Local/234@from-queue-00000006;2”, “recordcheck,1(dontcare,external,234)”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp(“Local/234@from-queue-00000006;2”, “Starting recording check against dontcare”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [recordcheck@sub-record-check:2] Goto(“Local/234@from-queue-00000006;2”, “dontcare”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [recordcheck@sub-record-check:3] Return(“Local/234@from-queue-00000006;2”, “”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [exten@sub-record-check:12] Return(“Local/234@from-queue-00000006;2”, “”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [234@from-queue-exten-only:12] Macro(“Local/234@from-queue-00000006;2”, “dial-one,HhTtr,234”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [s@macro-dial-one:1] Set(“Local/234@from-queue-00000006;2”, “DEXTEN=234”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [s@macro-dial-one:3] ExecIf(“Local/234@from-queue-00000006;2”, “1?Set(__EXTTOCALL=234)”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [s@macro-dial-one:4] Set(“Local/234@from-queue-00000006;2”, “DIALSTATUS_CW=”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [s@macro-dial-one:5] GosubIf(“Local/234@from-queue-00000006;2”, “0?screen,1()”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [s@macro-dial-one:6] GosubIf(“Local/234@from-queue-00000006;2”, “0?cf,1()”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [s@macro-dial-one:7] GotoIf(“Local/234@from-queue-00000006;2”, “1?skip1”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx_builtins.c: Goto (macro-dial-one,s,10)
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [s@macro-dial-one:10] GotoIf(“Local/234@from-queue-00000006;2”, “0?nodial”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [s@macro-dial-one:11] GotoIf(“Local/234@from-queue-00000006;2”, “0?continue”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [s@macro-dial-one:12] Set(“Local/234@from-queue-00000006;2”, “EXTHASCW=”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [s@macro-dial-one:13] GotoIf(“Local/234@from-queue-00000006;2”, “1?next1:cwinusebusy”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx_builtins.c: Goto (macro-dial-one,s,14)
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [s@macro-dial-one:14] GotoIf(“Local/234@from-queue-00000006;2”, “0?docfu:skip3”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx_builtins.c: Goto (macro-dial-one,s,18)
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [s@macro-dial-one:18] GotoIf(“Local/234@from-queue-00000006;2”, “1?next2:continue”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx_builtins.c: Goto (macro-dial-one,s,19)
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [s@macro-dial-one:19] GotoIf(“Local/234@from-queue-00000006;2”, “0?continue”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [s@macro-dial-one:20] ExecIf(“Local/234@from-queue-00000006;2”, “0?Set(DIALSTATUS=BUSY)”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [s@macro-dial-one:21] GotoIf(“Local/234@from-queue-00000006;2”, “0?cwinusebusy”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [s@macro-dial-one:22] Set(“Local/234@from-queue-00000006;2”, “DEXTEN=”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [s@macro-dial-one:23] Set(“Local/234@from-queue-00000006;2”, “DIALSTATUS=BUSY”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx.c: Executing [s@macro-dial-one:24] Goto(“Local/234@from-queue-00000006;2”, “nodial”) in new stack
[2023-03-28 09:01:04] VERBOSE[6345][C-00000071] pbx_builtins.c: Goto (macro-dial-one,s,61)
It seems that the queue doesn’t recognize the agent as busy and Asterisk tries to establish a call attempt, which then fails as the agent is actually busy.
Meanwhile thousands of unanswered calls lasting zero seconds are written in the queue_log
| 2023-03-28 09:01:04.491909 | 1679986832.122 | 401 | NONE | DID | | XXXXXXXXXX | | | | |
| 2023-03-28 09:01:04.496341 | 1679986832.122 | 401 | NONE | ENTERQUEUE | | | XXXXXXXXXX | 1 | | |
| 2023-03-28 09:01:04.961052 | 1679986832.122 | 401 | Elisa | RINGNOANSWER | | 0 | | | | |
| 2023-03-28 09:01:05.479302 | 1679986832.122 | 401 | Valentina | RINGNOANSWER | | 0 | | | | |
| 2023-03-28 09:01:06.481640 | 1679986832.122 | 401 | Agnese | RINGNOANSWER | | 0 | | | | |
| 2023-03-28 09:01:06.612523 | 1679986832.122 | 401 | Giada | RINGNOANSWER | | 0 | | | | |
| 2023-03-28 09:01:06.672353 | 1679986832.122 | 401 | Michela | RINGNOANSWER | | 0 | | | | |
| 2023-03-28 09:01:07.266438 | 1679986832.122 | 401 | Valentina | RINGNOANSWER | | 0 | | | | |
| 2023-03-28 09:01:08.869660 | 1679986832.122 | 401 | Francesco | RINGNOANSWER | | 0 | | | | |
| 2023-03-28 09:01:12.880557 | 1679986832.122 | 401 | Agnese | RINGNOANSWER | | 0 | | | | |
| 2023-03-28 09:01:13.920979 | 1679986851.124 | 401 | Samanta | RINGNOANSWER | | 0 | | | | |
| 2023-03-28 09:01:14.884443 | 1679986832.122 | 401 | Agnese | RINGNOANSWER | | 0 | | | | |
| 2023-03-28 09:01:15.801619 | 1679986832.122 | 401 | Francesco | RINGNOANSWER | | 0 | | | | |
| 2023-03-28 09:01:15.995067 | 1679986832.122 | 401 | Valeria | RINGNOANSWER | | 0 | | | | |
| 2023-03-28 09:01:17.576464 | 1679986832.122 | 401 | Valeria | CONNECT | | 12 | 1679986864.143 | 12 | | |
| 2023-03-28 09:02:47.667621 | 1679986832.122 | 401 | Valeria | COMPLETEAGENT | | 12 | 90 | 1 | | |
All this creates a huge load on Asterisk and Mysql until the whole process is slowed down and not being able to manage the sip traffic in time.