Exceptionally long voice queue length queuing and UNREACHABLE sip devices

hi
I have a serious issue with my server, calls from the queue are disconnected a few seconds after the answer.

in the log files this warning:
channel.c:1145 __ast_queue_frame: Exceptionally long voice queue length queuing to Local/1038@from-queue-0000da8e;2 repeated many times and so, many sip devices (chan_sip) going to unreachable

[2019-12-07 11:15:36] NOTICE[4187]: chan_sip.c:30169 sip_poke_noanswer: Peer '20129' is now UNREACHABLE!  Last qualify: 353
[2019-12-07 11:15:36] NOTICE[4187]: chan_sip.c:30169 sip_poke_noanswer: Peer '20019' is now UNREACHABLE!  Last qualify: 350
[2019-12-07 11:15:36] NOTICE[4187]: chan_sip.c:30169 sip_poke_noanswer: Peer '21013' is now UNREACHABLE!  Last qualify: 345
[2019-12-07 11:15:36] NOTICE[4187]: chan_sip.c:30169 sip_poke_noanswer: Peer '20085' is now UNREACHABLE!  Last qualify: 344
[2019-12-07 11:15:36] NOTICE[4187]: chan_sip.c:30169 sip_poke_noanswer: Peer '20126' is now UNREACHABLE!  Last qualify: 337
[2019-12-07 11:15:36] NOTICE[4187]: chan_sip.c:30169 sip_poke_noanswer: Peer '20201' is now UNREACHABLE!  Last qualify: 335
[2019-12-07 11:15:36] NOTICE[4187]: chan_sip.c:30169 sip_poke_noanswer: Peer '20242' is now UNREACHABLE!  Last qualify: 334
[2019-12-07 11:15:36] NOTICE[4187]: chan_sip.c:30169 sip_poke_noanswer: Peer '20151' is now UNREACHABLE!  Last qualify: 332
[2019-12-07 11:15:36] NOTICE[4187]: chan_sip.c:30169 sip_poke_noanswer: Peer '20107' is now UNREACHABLE!  Last qualify: 330
[2019-12-07 11:15:36] NOTICE[4187]: chan_sip.c:30169 sip_poke_noanswer: Peer '20105' is now UNREACHABLE!  Last qualify: 327
[2019-12-07 11:15:36] NOTICE[4187]: chan_sip.c:30169 sip_poke_noanswer: Peer '20164' is now UNREACHABLE!  Last qualify: 327
[2019-12-07 11:15:36] NOTICE[4187]: chan_sip.c:30169 sip_poke_noanswer: Peer '20137' is now UNREACHABLE!  Last qualify: 327

here are my server specs:
Asterisk 13.20
centos 6.6 64 bit
RAM: 12GB
CPU: 8 core
about 220 active calls and 120 agents in the queue.

I 've tried “/var/lib/asterisk/scripts/ast_coredumper --RUNNING --no-default-search” the output
Asterisk is not running
No coredumps found

I’d deal with the unreachable one first. That indicates you have problems with your network.

thank you for your reply
I checked network by pinging unreachable devices and packet loss and ping time were ok

Unreachable doesn’t use the voice queue.

Is this an overloaded virtual machine, or a virtual machine being moved between hosts?

let me more explain

there is two VM server one of them for asterisk service and the other one is MariaDB server, after resource checking on DB server I saw cpu iowait is about 15%

Is this can be the cause of the issue ?

I 've increased disk priority to high on esx server for DB server, I’ll wait and see what happens.

and another thing, this warning repeated many times:

taskprocessor.c:1110 taskprocessor_push: The ‘stasis/pool-control’ task processor queue reached 500 scheduled tasks again

I 've unloaded stasis modules but no changes.

 module show like stasis
Module                         Description                              Use Count  Status      Support Level
0 modules loaded

Does this resolve itself with intervention (overload), or do you have to restart Asterisk once these symptoms have started (debug as deadlock)?

Last time asterisk restart and even server restart did not help.

Today problem appeared just a few times and in almost of them cpu iowait was about 5-10%

I 'm going to find the process that waiting for the CPU

Hi, I hope to help. I used to have the same problem; the same messages about long voice queue, and then the peers start to being unreachable. The two messages are ralted, because the long voice means that ther lots of rtp packages in the queue of the channel (I see is a local channel involved with a peer) and because of that, the sip messages of the qualify (the option messages) are not processed either.
What I found is that, when I route the call to the agent, as I use local channels as well, I do some SQL query to validate some info and to insert some info to in my database (I use postgresql) and one of that query was taking to much time, so the anwered call was waiting to much and the “Exceptionally long voice queue…” started. So I was evaluating step by step every query I do in the local channel and correct the one that takes to much (I even have some deadlock ocurring in the database) and that was the problem.
That is my recomendation, look in the databse querys if somthing is taking to much time in between the call, even if you could share your dialplan maybe I can see if something is wrong or where can it be taking to much time processing.

SIP and RTP aren’t read on the same thread, so it would have to be a very severe backlog to reach a part of the network where the tow sorts of traffic were serialized with respect to each other.

I’d say the symptom is one of a general overload.

Thank for the clarification, I actually assume that based on what I saw, my mistake sorry. But What I recommend is true, then it must bee the overload of some process, but I seriusly recommend verifying what is happening during the local channel execution, or after the execution, as I said, In my case was a sql query before passing to the agent the call, it maybe is a Trigger that is taken to much too.

David551 and laar789 thank you for your answers

we use freepbx framework with some hacks in the dialplan , there is no SQL query or any kind of AGI ,but we use func_redis (GitHub - tic-ull/func_redis) to save some agents activity in REDIS server at the end of the call .
REDIS server hosted on another server on the same LAN network.

here is verbose log of queue local channel :

[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [1528@from-queue:1] Set(“Local/1528@from-queue-0002a47e;2”, “CDR(server_id)=1”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [1528@from-queue:2] Set(“Local/1528@from-queue-0002a47e;2”, “QAGENT=1528”) in new stack
[2019-12-12 13:44:39] VERBOSE[2025][C-00035e75] app_queue.c: Called Local/1528@from-queue/n
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [1528@from-queue:3] Set(“Local/1528@from-queue-0002a47e;2”, “__FROMQ=true”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [1528@from-queue:4] Set(“Local/1528@from-queue-0002a47e;2”, “D_OPTIONS=trM(auto-blkvm)I”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [1528@from-queue:5] Macro(“Local/1528@from-queue-0002a47e;2”, “dial-one,TtrM(auto-blkvm),1528”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:1] Set(“Local/1528@from-queue-0002a47e;2”, “DEXTEN=1528”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:2] ExecIf(“Local/1528@from-queue-0002a47e;2”, “1?Set(EXTTOCALL=1528)”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:3] Set(“Local/1528@from-queue-0002a47e;2”, “DIALSTATUS_CW=”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:4] GosubIf(“Local/1528@from-queue-0002a47e;2”, “0?screen,1()”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:5] GosubIf(“Local/1528@from-queue-0002a47e;2”, “0?cf,1()”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:6] GotoIf(“Local/1528@from-queue-0002a47e;2”, “1?skip1”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx_builtins.c: Goto (macro-dial-one,s,9)
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:9] GotoIf(“Local/1528@from-queue-0002a47e;2”, “0?nodial”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:10] GotoIf(“Local/1528@from-queue-0002a47e;2”, “0?continue”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:11] Set(“Local/1528@from-queue-0002a47e;2”, “EXTHASCW=”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:12] GotoIf(“Local/1528@from-queue-0002a47e;2”, “1?next1:cwinusebusy”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx_builtins.c: Goto (macro-dial-one,s,13)
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:13] GotoIf(“Local/1528@from-queue-0002a47e;2”, “0?docfu:skip3”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx_builtins.c: Goto (macro-dial-one,s,17)
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:17] GotoIf(“Local/1528@from-queue-0002a47e;2”, “1?next2:continue”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx_builtins.c: Goto (macro-dial-one,s,18)
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:18] GotoIf(“Local/1528@from-queue-0002a47e;2”, “1?continue”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx_builtins.c: Goto (macro-dial-one,s,26)
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:26] GotoIf(“Local/1528@from-queue-0002a47e;2”, “0?nodial”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:27] GosubIf(“Local/1528@from-queue-0002a47e;2”, “1?dstring,1():dlocal,1()”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [dstring@macro-dial-one:1] Set(“Local/1528@from-queue-0002a47e;2”, “DSTRING=”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [dstring@macro-dial-one:2] Set(“Local/1528@from-queue-0002a47e;2”, “DEVICES=1528&20268”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [dstring@macro-dial-one:3] ExecIf(“Local/1528@from-queue-0002a47e;2”, “0?Return()”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [dstring@macro-dial-one:4] ExecIf(“Local/1528@from-queue-0002a47e;2”, “0?Set(DEVICES=528&20268)”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [dstring@macro-dial-one:5] Set(“Local/1528@from-queue-0002a47e;2”, “LOOPCNT=2”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [dstring@macro-dial-one:6] Set(“Local/1528@from-queue-0002a47e;2”, “ITER=1”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [dstring@macro-dial-one:7] Set(“Local/1528@from-queue-0002a47e;2”, “THISDIAL=”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [dstring@macro-dial-one:8] GosubIf(“Local/1528@from-queue-0002a47e;2”, “1?zap2dahdi,1()”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [zap2dahdi@macro-dial-one:1] ExecIf(“Local/1528@from-queue-0002a47e;2”, “1?Return()”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [dstring@macro-dial-one:9] GotoIf(“Local/1528@from-queue-0002a47e;2”, “1?docheck”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx_builtins.c: Goto (macro-dial-one,dstring,14)
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [dstring@macro-dial-one:14] GotoIf(“Local/1528@from-queue-0002a47e;2”, “1?skipset”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx_builtins.c: Goto (macro-dial-one,dstring,16)
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [dstring@macro-dial-one:16] Set(“Local/1528@from-queue-0002a47e;2”, “ITER=2”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [dstring@macro-dial-one:17] GotoIf(“Local/1528@from-queue-0002a47e;2”, “1?begin”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx_builtins.c: Goto (macro-dial-one,dstring,7)
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [dstring@macro-dial-one:7] Set(“Local/1528@from-queue-0002a47e;2”, “THISDIAL=SIP/20268”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [dstring@macro-dial-one:8] GosubIf(“Local/1528@from-queue-0002a47e;2”, “1?zap2dahdi,1()”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [zap2dahdi@macro-dial-one:1] ExecIf(“Local/1528@from-queue-0002a47e;2”, “0?Return()”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [zap2dahdi@macro-dial-one:2] Set(“Local/1528@from-queue-0002a47e;2”, “NEWDIAL=”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [zap2dahdi@macro-dial-one:3] Set(“Local/1528@from-queue-0002a47e;2”, “LOOPCNT2=1”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [zap2dahdi@macro-dial-one:4] Set(“Local/1528@from-queue-0002a47e;2”, “ITER2=1”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [zap2dahdi@macro-dial-one:5] Set(“Local/1528@from-queue-0002a47e;2”, “THISPART2=SIP/20268”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [zap2dahdi@macro-dial-one:6] ExecIf(“Local/1528@from-queue-0002a47e;2”, “0?Set(THISPART2=DAHDI/20268)”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [zap2dahdi@macro-dial-one:7] Set(“Local/1528@from-queue-0002a47e;2”, “NEWDIAL=SIP/20268&”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [zap2dahdi@macro-dial-one:8] Set(“Local/1528@from-queue-0002a47e;2”, “ITER2=2”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [zap2dahdi@macro-dial-one:9] GotoIf(“Local/1528@from-queue-0002a47e;2”, “0?begin2”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [zap2dahdi@macro-dial-one:10] Set(“Local/1528@from-queue-0002a47e;2”, “THISDIAL=SIP/20268”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [zap2dahdi@macro-dial-one:11] Return(“Local/1528@from-queue-0002a47e;2”, “”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [dstring@macro-dial-one:9] GotoIf(“Local/1528@from-queue-0002a47e;2”, “1?docheck”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx_builtins.c: Goto (macro-dial-one,dstring,14)
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [dstring@macro-dial-one:14] GotoIf(“Local/1528@from-queue-0002a47e;2”, “0?skipset”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [dstring@macro-dial-one:15] Set(“Local/1528@from-queue-0002a47e;2”, “DSTRING=SIP/20268&”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [dstring@macro-dial-one:16] Set(“Local/1528@from-queue-0002a47e;2”, “ITER=3”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [dstring@macro-dial-one:17] GotoIf(“Local/1528@from-queue-0002a47e;2”, “0?begin”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [dstring@macro-dial-one:18] ExecIf(“Local/1528@from-queue-0002a47e;2”, “0?Return()”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [dstring@macro-dial-one:19] Set(“Local/1528@from-queue-0002a47e;2”, “DSTRING=SIP/20268”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [dstring@macro-dial-one:20] Return(“Local/1528@from-queue-0002a47e;2”, “”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:28] GotoIf(“Local/1528@from-queue-0002a47e;2”, “0?nodial”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:29] GotoIf(“Local/1528@from-queue-0002a47e;2”, “0?skiptrace”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:30] GosubIf(“Local/1528@from-queue-0002a47e;2”, “1?ctset,1():ctclear,1()”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [ctset@macro-dial-one:1] Set(“Local/1528@from-queue-0002a47e;2”, “DB(CALLTRACE/1528)=88982343”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [ctset@macro-dial-one:2] Return(“Local/1528@from-queue-0002a47e;2”, “”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:31] Set(“Local/1528@from-queue-0002a47e;2”, “D_OPTIONS=TtrM(auto-blkvm)”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:32] NoOp(“Local/1528@from-queue-0002a47e;2”, "Blind Transfer: , Attended Transfer: , User: , Alert Info: ") in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:33] ExecIf(“Local/1528@from-queue-0002a47e;2”, “0?Set(ALERT_INFO=)”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:34] ExecIf(“Local/1528@from-queue-0002a47e;2”, “0?Set(ALERT_INFO=)”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:35] ExecIf(“Local/1528@from-queue-0002a47e;2”, “0?Set(ALERT_INFO=)”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:36] ExecIf(“Local/1528@from-queue-0002a47e;2”, “0?Set(ALERT_INFO=Normal;volume=)”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:37] ExecIf(“Local/1528@from-queue-0002a47e;2”, “0?Set(ALERT_INFO=Normal;volume=)”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:38] GosubIf(“Local/1528@from-queue-0002a47e;2”, “0?func-set-sipheader,s,1(Alert-Info,)”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:39] ExecIf(“Local/1528@from-queue-0002a47e;2”, “0?Set(CHANNEL(musicclass)=)”) in new stack
[2019-12-12 13:44:39] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:40] GosubIf(“Local/1528@from-queue-0002a47e;2”, “0?qwait,1()”) in new stack
[2019-12-12 13:44:40] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:41] Set(“Local/1528@from-queue-0002a47e;2”, “__CWIGNORE=TRUE”) in new stack
[2019-12-12 13:44:40] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:42] Set(“Local/1528@from-queue-0002a47e;2”, “__KEEPCID=TRUE”) in new stack
[2019-12-12 13:44:40] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:43] GotoIf(“Local/1528@from-queue-0002a47e;2”, “0?usegoto,1”) in new stack
[2019-12-12 13:44:40] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:44] GotoIf(“Local/1528@from-queue-0002a47e;2”, “1?godial”) in new stack
[2019-12-12 13:44:40] VERBOSE[11647][C-00035e75] pbx_builtins.c: Goto (macro-dial-one,s,49)
[2019-12-12 13:44:40] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:49] Macro(“Local/1528@from-queue-0002a47e;2”, “dialout-one-predial-hook,”) in new stack
[2019-12-12 13:44:40] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dialout-one-predial-hook:1] MacroExit(“Local/1528@from-queue-0002a47e;2”, “”) in new stack
[2019-12-12 13:44:40] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:50] ExecIf(“Local/1528@from-queue-0002a47e;2”, “1?Set(D_OPTIONS=trM(auto-blkvm)I)”) in new stack
[2019-12-12 13:44:40] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:51] NoOp(“Local/1528@from-queue-0002a47e;2”, “”) in new stack
[2019-12-12 13:44:40] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-dial-one:52] Dial(“Local/1528@from-queue-0002a47e;2”, “SIP/20268,trM(auto-blkvm)Ib(func-apply-sipheaders^s^1)”) in new stack
[2019-12-12 13:44:40] VERBOSE[11647][C-00035e75] netsock2.c: Using SIP RTP TOS bits 184
[2019-12-12 13:44:40] VERBOSE[11647][C-00035e75] netsock2.c: Using SIP RTP CoS mark 5
[2019-12-12 13:44:40] VERBOSE[11647][C-00035e75] app_stack.c: SIP/20268-00058796 Internal Gosub(func-apply-sipheaders,s,1) start
[2019-12-12 13:44:40] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@func-apply-sipheaders:1] NoOp(“SIP/20268-00058796”, “Applying SIP Headers to channel”) in new stack
[2019-12-12 13:44:40] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@func-apply-sipheaders:2] Set(“SIP/20268-00058796”, “SIPHEADERKEYS=”) in new stack
[2019-12-12 13:44:40] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@func-apply-sipheaders:3] While(“SIP/20268-00058796”, “0”) in new stack
[2019-12-12 13:44:40] VERBOSE[11647][C-00035e75] app_while.c: Jumping to priority 7
[2019-12-12 13:44:40] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@func-apply-sipheaders:8] Return(“SIP/20268-00058796”, “”) in new stack
[2019-12-12 13:44:40] VERBOSE[11647][C-00035e75] app_stack.c: Spawn extension (from-internal, 1528, 1) exited non-zero on ‘SIP/20268-00058796’
[2019-12-12 13:44:40] VERBOSE[11647][C-00035e75] app_stack.c: SIP/20268-00058796 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
[2019-12-12 13:44:40] VERBOSE[11647][C-00035e75] app_dial.c: Called SIP/20268
[2019-12-12 13:44:40] VERBOSE[11647][C-00035e75] app_dial.c: Connected line update to Local/1528@from-queue-0002a47e;2 prevented.
[2019-12-12 13:44:40] VERBOSE[2025][C-00035e75] app_queue.c: Local/1528@from-queue-0002a47e;1 is ringing
[2019-12-12 13:44:40] VERBOSE[11647][C-00035e75] app_dial.c: SIP/20268-00058796 is ringing
[2019-12-12 13:44:40] VERBOSE[2025][C-00035e75] app_queue.c: Local/1528@from-queue-0002a47e;1 is ringing
[2019-12-12 13:44:43] VERBOSE[11647][C-00035e75] app_dial.c: Connected line update to Local/1528@from-queue-0002a47e;2 prevented.
[2019-12-12 13:44:43] VERBOSE[11647][C-00035e75] app_dial.c: SIP/20268-00058796 answered Local/1528@from-queue-0002a47e;2
[2019-12-12 13:44:43] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-auto-blkvm:1] ExecIf(“SIP/20268-00058796”, “1?Set(CDR(recordingfile)=q-2018-88982343-20191212-134051-1576145451.711307.WAV)”) in new stack
[2019-12-12 13:44:43] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-auto-blkvm:2] UserEvent(“SIP/20268-00058796”, “agentoconnecto,20268::1”) in new stack
[2019-12-12 13:44:43] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-auto-blkvm:3] Set(“SIP/20268-00058796”, “CDR(queue_operator)=1528”) in new stack

[2019-12-12 13:44:43] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-auto-blkvm:4] Set(“SIP/20268-00058796”, “__MACRO_RESULT=”) in new stack
[2019-12-12 13:44:43] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-auto-blkvm:5] Set(“SIP/20268-00058796”, “CFIGNORE=”) in new stack
[2019-12-12 13:44:43] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-auto-blkvm:6] Set(“SIP/20268-00058796”, “MASTER_CHANNEL(CFIGNORE)=”) in new stack
[2019-12-12 13:44:43] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-auto-blkvm:7] Set(“SIP/20268-00058796”, “FORWARD_CONTEXT=from-internal”) in new stack
[2019-12-12 13:44:43] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-auto-blkvm:8] Set(“SIP/20268-00058796”, “MASTER_CHANNEL(FORWARD_CONTEXT)=from-internal”) in new stack
[2019-12-12 13:44:43] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-auto-blkvm:9] Macro(“SIP/20268-00058796”, “blkvm-clr,”) in new stack
[2019-12-12 13:44:43] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-blkvm-clr:1] Set(“SIP/20268-00058796”, “SHARED(BLKVM,SIP/gw1-telco-00058632)=”) in new stack
[2019-12-12 13:44:43] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-blkvm-clr:2] Set(“SIP/20268-00058796”, “GOSUB_RETVAL=”) in new stack
[2019-12-12 13:44:43] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-blkvm-clr:3] MacroExit(“SIP/20268-00058796”, “”) in new stack
[2019-12-12 13:44:43] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-auto-blkvm:10] ExecIf(“SIP/20268-00058796”, “0?Set(MASTER_CHANNEL(CONNECTEDLINE(num))=20268)”) in new stack
[2019-12-12 13:44:43] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-auto-blkvm:11] ExecIf(“SIP/20268-00058796”, “0?Set(MASTER_CHANNEL(CONNECTEDLINE(name))=)”) in new stack
[2019-12-12 13:44:43] VERBOSE[2025][C-00035e75] app_queue.c: Local/1528@from-queue-0002a47e;1 answered SIP/gw1-telco-00058632
[2019-12-12 13:44:43] VERBOSE[11942][C-00035e75] bridge_channel.c: Channel SIP/20268-00058796 joined ‘simple_bridge’ basic-bridge <72e3ddf9-3f18-41ca-9437-423ad46b15b1>
[2019-12-12 13:44:43] VERBOSE[11647][C-00035e75] bridge_channel.c: Channel Local/1528@from-queue-0002a47e;2 joined ‘simple_bridge’ basic-bridge <72e3ddf9-3f18-41ca-9437-423ad46b15b1>
[2019-12-12 13:44:45] WARNING[11647][C-00035e75] channel.c: Exceptionally long voice queue length queuing to Local/1528@from-queue-0002a47e;1
[2019-12-12 13:44:45] VERBOSE[2025][C-00035e75] res_musiconhold.c: Stopped music on hold on SIP/gw1-telco-00058632
[2019-12-12 13:44:46] WARNING[11647][C-00035e75] channel.c: Exceptionally long voice queue length queuing to Local/1528@from-queue-0002a47e;1
[2019-12-12 13:44:46] VERBOSE[12075][C-00035e75] bridge_channel.c: Channel Local/1528@from-queue-0002a47e;1 joined ‘simple_bridge’ basic-bridge
[2019-12-12 13:44:46] VERBOSE[2025][C-00035e75] bridge_channel.c: Channel SIP/gw1-telco-00058632 joined ‘simple_bridge’ basic-bridge
[2019-12-12 13:47:30] VERBOSE[2025][C-00035e75] bridge_channel.c: Channel SIP/gw1-telco-00058632 left ‘simple_bridge’ basic-bridge
[2019-12-12 13:47:30] VERBOSE[12075][C-00035e75] bridge_channel.c: Channel Local/1528@from-queue-0002a47e;1 left ‘simple_bridge’ basic-bridge
[2019-12-12 13:47:30] VERBOSE[2025][C-00035e75] pbx.c: Executing [h@ext-queues:1] Macro(“SIP/gw1-telco-00058632”, “hangupcall,”) in new stack
[2019-12-12 13:47:30] VERBOSE[11647][C-00035e75] bridge_channel.c: Channel Local/1528@from-queue-0002a47e;2 left ‘simple_bridge’ basic-bridge <72e3ddf9-3f18-41ca-9437-423ad46b15b1>
[2019-12-12 13:47:30] WARNING[11647][C-00035e75] taskprocessor.c: The ‘stasis/pool-control’ task processor queue reached 500 scheduled tasks again.
[2019-12-12 13:47:30] WARNING[11647][C-00035e75] taskprocessor.c: The ‘stasis/pool-control’ task processor queue reached 500 scheduled tasks again.
[2019-12-12 13:47:30] VERBOSE[11942][C-00035e75] bridge_channel.c: Channel SIP/20268-00058796 left ‘simple_bridge’ basic-bridge <72e3ddf9-3f18-41ca-9437-423ad46b15b1>
[2019-12-12 13:47:30] VERBOSE[2025][C-00035e75] pbx.c: Executing [s@macro-hangupcall:1] GotoIf(“SIP/gw1-telco-00058632”, “0?redis:start”) in new stack
[2019-12-12 13:47:30] VERBOSE[11647][C-00035e75] app_macro.c: Spawn extension (macro-dial-one, s, 52) exited non-zero on ‘Local/1528@from-queue-0002a47e;2’ in macro ‘dial-one’
[2019-12-12 13:47:30] VERBOSE[2025][C-00035e75] pbx_builtins.c: Goto (macro-hangupcall,s,8)
[2019-12-12 13:47:30] VERBOSE[2025][C-00035e75] pbx.c: Executing [s@macro-hangupcall:8] ExecIf(“SIP/gw1-telco-00058632”, “0?UserEvent(outgoing,88982343::ANSWERED)”) in new stack
[2019-12-12 13:47:30] WARNING[11942][C-00035e75] taskprocessor.c: The ‘stasis/pool-control’ task processor queue reached 500 scheduled tasks again.
[2019-12-12 13:47:30] VERBOSE[11647][C-00035e75] pbx.c: Spawn extension (from-queue, 1528, 5) exited non-zero on ‘Local/1528@from-queue-0002a47e;2’
[2019-12-12 13:47:30] VERBOSE[2025][C-00035e75] pbx.c: Executing [s@macro-hangupcall:9] GotoIf(“SIP/gw1-telco-00058632”, “1?theend”) in new stack
[2019-12-12 13:47:30] VERBOSE[11647][C-00035e75] pbx.c: Executing [h@from-queue:1] Macro(“Local/1528@from-queue-0002a47e;2”, “hangupcall,”) in new stack
[2019-12-12 13:47:30] VERBOSE[2025][C-00035e75] pbx_builtins.c: Goto (macro-hangupcall,s,11)
[2019-12-12 13:47:30] VERBOSE[2025][C-00035e75] pbx.c: Executing [s@macro-hangupcall:11] ExecIf(“SIP/gw1-telco-00058632”, “0?Set(CDR(recordingfile)=)”) in new stack
[2019-12-12 13:47:30] VERBOSE[2025][C-00035e75] pbx.c: Executing [s@macro-hangupcall:12] NoOp(“SIP/gw1-telco-00058632”, "reza: q-2018-88982343-20191212-134051-1576145451.711307.WAV – ") in new stack
[2019-12-12 13:47:30] VERBOSE[2025][C-00035e75] pbx.c: Executing [s@macro-hangupcall:13] Hangup(“SIP/gw1-telco-00058632”, “”) in new stack
[2019-12-12 13:47:30] VERBOSE[2025][C-00035e75] app_macro.c: Spawn extension (macro-hangupcall, s, 13) exited non-zero on ‘SIP/gw1-telco-00058632’ in macro ‘hangupcall’
[2019-12-12 13:47:30] VERBOSE[2025][C-00035e75] pbx.c: Spawn extension (ext-queues, h, 1) exited non-zero on ‘SIP/gw1-telco-00058632’
[2019-12-12 13:47:30] VERBOSE[3465][C-00035e75] app_mixmonitor.c: MixMonitor close filestream (mixed)
[2019-12-12 13:47:30] VERBOSE[3465][C-00035e75] app_mixmonitor.c: End MixMonitor Recording SIP/gw1-telco-00058632
> [2019-12-12 13:47:30] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-hangupcall:1] GotoIf(“Local/1528@from-queue-0002a47e;2”, “1?redis:start”) in new stack
> [2019-12-12 13:47:30] VERBOSE[11647][C-00035e75] pbx_builtins.c: Goto (macro-hangupcall,s,4)
> [2019-12-12 13:47:30] DEBUG[11647][C-00035e75] /root/func_redis/src/func_redis.c: Selecting DB 0
> [2019-12-12 13:47:30] DEBUG[11647][C-00035e75] /root/func_redis/src/func_redis.c: Database 0 selected.
[2019-12-12 13:47:30] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-hangupcall:4] Set(“Local/1528@from-queue-0002a47e;2”, “hichi=OK”) in new stack
[2019-12-12 13:47:30] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-hangupcall:5] Set(“Local/1528@from-queue-0002a47e;2”, “hichi=OK”) in new stack
[2019-12-12 13:47:30] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-hangupcall:6] Set(“Local/1528@from-queue-0002a47e;2”, “hichi=OK”) in new stack
[2019-12-12 13:47:30] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-hangupcall:7] NoOp(“Local/1528@from-queue-0002a47e;2”, “OK”) in new stack
[2019-12-12 13:47:30] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-hangupcall:8] ExecIf(“Local/1528@from-queue-0002a47e;2”, “0?UserEvent(outgoing,88982343::ANSWERED)”) in new stack
[2019-12-12 13:47:30] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-hangupcall:9] GotoIf(“Local/1528@from-queue-0002a47e;2”, “1?theend”) in new stack
[2019-12-12 13:47:30] VERBOSE[11647][C-00035e75] pbx_builtins.c: Goto (macro-hangupcall,s,11)
[2019-12-12 13:47:30] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-hangupcall:11] ExecIf(“Local/1528@from-queue-0002a47e;2”, “0?Set(CDR(recordingfile)=)”) in new stack
[2019-12-12 13:47:30] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-hangupcall:12] NoOp(“Local/1528@from-queue-0002a47e;2”, "reza: – ") in new stack
[2019-12-12 13:47:30] VERBOSE[11647][C-00035e75] pbx.c: Executing [s@macro-hangupcall:13] Hangup(“Local/1528@from-queue-0002a47e;2”, “”) in new stack
[2019-12-12 13:47:30] VERBOSE[11647][C-00035e75] app_macro.c: Spawn extension (macro-hangupcall, s, 13) exited non-zero on ‘Local/1528@from-queue-0002a47e;2’ in macro ‘hangupcall’
[2019-12-12 13:47:30] VERBOSE[11647][C-00035e75] pbx.c: Spawn extension (from-queue, h, 1) exited non-zero on ‘Local/1528@from-queue-0002a47e;2’

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