Calls in queues get transferred to agent's voicemail

gsoucy · October 29, 2019, 4:58pm

Hello,

We have configured 2 call queues on which many agents login and logout dynamically. We want the calls to remain in the queue until one of the agents takes it. It works fine for most agents. For one of them, always the same, some calls from the queue go straight to the agent’s voicemail . Not all the time but often.

From looking at the CDR logs, I can see that this seems to happen on the second time the call is proposed to this agent. On the first round, if this agent does not answer, the call goes to the other agents as it should. However, on the second round, the call goes to the voicemail of that agent and ends there. Naturally, this is not what we want.

In principle, this agent’s config is the same as all others. I compared the configs and I cannot see anything special. We changed the physical phone and also the extension.

Our installation is pretty old: we have FreePBX 2.10 and asterisk 1.8.15.1 .

Here is an example of a sequence where the call goes to the agent’s voice mail

On item 1 , the call gets into the queue. On item 2, it gets proposed to the agent 273 for the first time and is not taken. On item 3, the call is sent to the voicemail of agent 273.

Is there any setting that could cause this sequence of events to happen ?

Any hint would be useful.

Thank you

Gilbert

partgenius · October 29, 2019, 5:09pm

Do you have the queue set to disable call forwarding and FindMe. Show us your queue config.

gsoucy · October 29, 2019, 7:54pm

Here is extensions_additional.conf

exten => 620,1,Macro(user-callerid,)
exten => 620,n,Answer
exten => 620,n,Macro(blkvm-set,reset)
exten => 620,n,ExecIf($["${REGEX("(M[(]auto-blkvm[)])" ${DIAL_OPTIONS})}" != “1”]?Set(_DIAL_OPTIONS=${DIAL_OPTIONS}M(auto-blkvm)))
exten => 620,n,Set(__NODEST=${EXTEN})
exten => 620,n,Set(__MIXMON_FORMAT=wav)
exten => 620,n,Gosub(sub-record-check,s,1(q,620,always))
exten => 620,n,Set(__CWIGNORE=TRUE)
exten => 620,n,QueueLog(620,${UNIQUEID},NONE,DID,${FROM_DID})
exten => 620,n,Queue(620,t,)
exten => 620,n,Macro(blkvm-clr,)
exten => 620,n,Gosub(sub-record-cancel,s,1())
exten => 620,n,Set(__NODEST=)
exten => 620,n,Set(__CWIGNORE=)
exten => 620,n,Goto(ext-local,vmu301,1)

exten => 620*,1,Macro(agent-add,620,)

exten => 620**,1,Macro(agent-del,620)

exten => *45620,1,Set(QUEUENO=620)
exten => *45620,n,Goto(app-queue-toggle,s,start)

and here is queues_additionnal.conf

[620]
announce-frequency=0
announce-holdtime=no
announce-position=no
autofill=no
eventmemberstatus=no
eventwhencalled=no
joinempty=no
leavewhenempty=yes
maxlen=0
memberdelay=0
monitor-type=mixmonitor
monitor-format=wav
penaltymemberslimit=0
periodic-announce-frequency=360
queue-callswaiting=silence/1
queue-thereare=silence/1
queue-youarenext=silence/1
reportholdtime=no
retry=5
ringinuse=yes
servicelevel=60
strategy=ringall
timeout=15
timeoutpriority=app
timeoutrestart=no
weight=0
wrapuptime=0
context=ivr-22
periodic-announce=custom/BreakOut

I guess, this is not good:

exten => 620,n,Queue(620,t,)

https://www.voip-info.org/asterisk-cmd-queue/

 t — allow the called user to transfer the calling user.

However, I cannot see how to change that in the FreePBX interface…

partgenius · October 29, 2019, 8:44pm

What is your failover destination? Sorry I’m terrible at reading the config. If you have any screenshots of the gui that might help better.

My guess is it’s due to agent restrictions…or failover, but I would need to see it in the gui format.

gsoucy · October 29, 2019, 9:03pm

The failover is a virtual voicemail (ext 301) where all calls get centralized.

Here are the screen shots

partgenius · October 29, 2019, 9:15pm

Set your agent restrictions to No Follow Me or Call Forward and see if that fixes the problem.

PitzKey · October 29, 2019, 9:37pm

Post an actual call log.

Did you modify the queue config file?

gsoucy · October 29, 2019, 10:08pm

I had not seen this option. I have set it and we will see tomorrow.

gsoucy · October 29, 2019, 10:13pm

I can see the result of that setting in extensions_additional.conf ( CF_IGNORE and __FORWARD_CONTEXT where added ):

exten => 620,1,Macro(user-callerid,)
exten => 620,n,Answer
exten => 620,n,Macro(blkvm-set,reset)
exten => 620,n,ExecIf($["${REGEX("(M[(]auto-blkvm[)])" ${DIAL_OPTIONS})}" != “1”]?Set(_DIAL_OPTIONS=${DIAL_OPTIONS}M(auto-blkvm)))
exten => 620,n,Set(__NODEST=${EXTEN})
exten => 620,n,Set(__MIXMON_FORMAT=wav)
exten => 620,n,Gosub(sub-record-check,s,1(q,620,always))
exten => 620,n,Set(__CWIGNORE=TRUE)
exten => 620,n,Set(__CFIGNORE=TRUE)
exten => 620,n,Set(__FORWARD_CONTEXT=block-cf)
exten => 620,n,QueueLog(620,${UNIQUEID},NONE,DID,${FROM_DID})
exten => 620,n,Queue(620,t,)
exten => 620,n,Macro(blkvm-clr,)
exten => 620,n,Gosub(sub-record-cancel,s,1())
exten => 620,n,Set(__NODEST=)
exten => 620,n,Set(__CWIGNORE=)
exten => 620,n,Set(__CFIGNORE=)
exten => 620,n,Set(__FORWARD_CONTEXT=from-internal)
exten => 620,n,Goto(ext-local,vmu301,1)

exten => 620*,1,Macro(agent-add,620,)

exten => 620**,1,Macro(agent-del,620)

gsoucy · October 29, 2019, 10:30pm

I did not edit the config files manually.

I attach a txt file of a call log ( item 24261 ) where we can see a call being send to the voicemail of 273. It is very verbose.

The little I understand for the log is that it seems that ext 248 is forwarding the call to 273, around 10:21:46.

I apologize for the length of this log, I am not sure if there is a smarter way to attach it (cannot upload txt files…)

============================
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: [2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:1] Set(“Local/[email protected];2”, “QAGENT=248”) in new stack
– Executing [[email protected]:2] Goto(“Local/[email protected];2”, “620,1”) in new stack
– Goto (from-queue,620,1)
– Executing [[email protected]:1] Goto(“Local/[email protected];2”, “from-internal,248,1”) in new stack
– Goto (from-internal,248,1)
– Executing [[email protected]:1] Set(“Local/[email protected];2”, “__RINGTIMER=15”) in new stack
– Executing [[email protected]:2] Macro(“Local/[email protected];2”, “exten-vm,248,248,0,0,0”) in new stack
– Executing [[email protected]:1] Macro(“Local/[email protected];2”, “user-callerid,”) in new stack
– Executing [[email protected]:1] Set(“Local/[email protected];2”, “AMPUSER=4388880916”) in new stack
– Executing [[email protected]:2] GotoIf(“Local/[email protected];2”, “1?report”) in new stack
– Goto (macro-user-callerid,s,12)
– Executing [[email protected]:12] GotoIf(“Local/[email protected];2”, “0?continue”) in new stack
– Executing [[email protected]:13] Set(“Local/[email protected];2”, “__TTL=63”) in new stack
– Executing [[email protected]:14] GotoIf(“Local/[email protected];2”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,25)
– Executing [[email protected]:25] Set(“Local/[email protected];2”, “CALLERID(number)=4388880916”) in new stack
– Executing [[email protected]:26] Set(“Local/[email protected];2”, “CALLERID(name)=NC-4388880916”) in new stack
– Executing [[email protected]:27] Set(“Local/[email protected];2”, “CHANNEL(language)=fr”) in new stack
– Executing [[email protected]:2] Set(“Local/[email protected];2”, “RingGroupMethod=none”) in new stack
– Executing [[email protected]:3] Set(“Local/[email protected];2”, “__EXTTOCALL=248”) in new stack
– Executing [[email protected]:4] Set(“Local/[email protected];2”, “__PICKUPMARK=248”) in new stack
– Executing [[email protected]:5] Set(“Local/[email protected];2”, “RT=15”) in new stack
– Executing [[email protected]:6] Gosub(“Local/[email protected];2”, “sub-record-check,s,1(exten,248,)”) in new stack
– Executing [[email protected]:1] GotoIf(“Local/[email protected];2”, “1?check”) in new stack
– Goto (sub-record-check,s,6)
– Executing [[email protected]:6] Set(“Local/[email protected];2”, “__MON_FMT=wav”) in new stack
– Executing [[email protected]:7] GotoIf(“Local/[email protected];2”, “0?next”) in new stack
– Executing [[email protected]:8] Set(“Local/[email protected];2”, “CDR(recordingfile)=q-620-4388880916-20191029-102139-1572358809.241730.wav”) in new stack
– Executing [[email protected]:9] Return(“Local/[email protected];2”, “”) in new stack
– Executing [[email protected]:7] GotoIf(“Local/[email protected];2”, “10?macrodial”) in new stack
– Goto (macro-exten-vm,s,13)
– Executing [[email protected]:13] GosubIf(“Local/[email protected];2”, “0?clrheader,1()”) in new stack
– Executing [[email protected]:14] Macro(“Local/[email protected];2”, “dial-one,15,trM(auto-blkvm),248”) in new stack
– Executing [[email protected]:1] Set(“Local/[email protected];2”, “DEXTEN=248”) in new stack

[…removed a few lines as it was too long for the system…]

GotoIf(“Local/[email protected];2”, “1?next1:cwinusebusy”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Goto (macro-dial-one,s,12)
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:12] GotoIf(“Local/[email protected];2”, “0?docfu:skip3”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Goto (macro-dial-one,s,16)
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:16] GotoIf(“Local/[email protected];2”, “1?next2:continue”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Goto (macro-dial-one,s,17)
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:17] GotoIf(“Local/[email protected];2”, “1?continue”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Goto (macro-dial-one,s,25)
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:25] GotoIf(“Local/[email protected];2”, “0?nodial”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:26] GosubIf(“Local/[email protected];2”, “1?dstring,1():dlocal,1()”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:1] Set(“Local/[email protected];2”, “DSTRING=”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:2] Set(“Local/[email protected];2”, “DEVICES=248”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:3] ExecIf(“Local/[email protected];2”, “0?Return()”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:4] ExecIf(“Local/[email protected];2”, “0?Set(DEVICES=48)”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:5] Set(“Local/[email protected];2”, “LOOPCNT=1”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:6] Set(“Local/[email protected];2”, “ITER=1”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:7] Set(“Local/[email protected];2”, “THISDIAL=SIP/248”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:8] GosubIf(“Local/[email protected];2”, “1?zap2dahdi,1()”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:1] ExecIf(“Local/[email protected];2”, “0?Return()”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:2] Set(“Local/[email protected];2”, “NEWDIAL=”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:3] Set(“Local/[email protected];2”, “LOOPCNT2=1”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:4] Set(“Local/[email protected];2”, “ITER2=1”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:5] Set(“Local/[email protected];2”, “THISPART2=SIP/248”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:6] ExecIf(“Local/[email protected];2”, “0?Set(THISPART2=DAHDI/248)”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:7] Set(“Local/[email protected];2”, “NEWDIAL=SIP/248&”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:8] Set(“Local/[email protected];2”, “ITER2=2”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:9] GotoIf(“Local/[email protected];2”, “0?begin2”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:10] Set(“Local/[email protected];2”, “THISDIAL=SIP/248”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:11] Return(“Local/[email protected];2”, “”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:9] Set(“Local/[email protected];2”, “DSTRING=SIP/248&”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:10] Set(“Local/[email protected];2”, “ITER=2”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:11] GotoIf(“Local/[email protected];2”, “0?begin”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:12] Set(“Local/[email protected];2”, “DSTRING=SIP/248”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:13] Return(“Local/[email protected];2”, “”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:27] GotoIf(“Local/[email protected];2”, “0?nodial”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:28] GotoIf(“Local/[email protected];2”, “0?skiptrace”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:29] GosubIf(“Local/[email protected];2”, “1?ctset,1():ctclear,1()”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:1] Set(“Local/[email protected]5c;2”, “DB(CALLTRACE/248)=4388880916”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:2] Return(“Local/[email protected];2”, “”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:30] Set(“Local/[email protected];2”, “D_OPTIONS=trM(auto-blkvm)”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:31] ExecIf(“Local/[email protected];2”, “1?SIPAddHeader(Alert-Info: )”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:32] ExecIf(“Local/[email protected];2”, “0?SIPAddHeader()”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:33] ExecIf(“Local/[email protected];2”, “0?Set(CHANNEL(musicclass)=)”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:34] GosubIf(“Local/[email protected];2”, “0?qwait,1()”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:35] Set(“Local/[email protected];2”, “__CWIGNORE=TRUE”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:36] Set(“Local/[email protected];2”, “__KEEPCID=TRUE”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:37] GotoIf(“Local/[email protected];2”, “0?usegoto,1”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:38] GotoIf(“Local/[email protected];2”, “1?godial”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Goto (macro-dial-one,s,42)
[2019-10-29 10:21:39] VERBOSE[24261] pbx.c: – Executing [[email protected]:42] Dial(“Local/[email protected];2”, “SIP/248,15,trM(auto-blkvm)”) in new stack
[2019-10-29 10:21:39] VERBOSE[24261] netsock2.c: == Using SIP RTP TOS bits 184
[2019-10-29 10:21:39] VERBOSE[24261] netsock2.c: == Using SIP RTP CoS mark 5
[2019-10-29 10:21:39] VERBOSE[24261] app_dial.c: – Called SIP/248
[2019-10-29 10:21:39] VERBOSE[24261] app_dial.c: – SIP/248-0000d7d8 is ringing
[2019-10-29 10:21:43] VERBOSE[24261] app_dial.c: – SIP/248-0000d7d8 answered Local/[email protected];2
[2019-10-29 10:21:43] VERBOSE[24261] pbx.c: – Executing [[email protected]:1] Set(“SIP/248-0000d7d8”, “__MACRO_RESULT=”) in new stack
[2019-10-29 10:21:43] VERBOSE[24261] pbx.c: – Executing [[email protected]:2] Macro(“SIP/248-0000d7d8”, “blkvm-clr,”) in new stack
[2019-10-29 10:21:43] VERBOSE[24261] pbx.c: – Executing [[email protected]:1] Set(“SIP/248-0000d7d8”, “SHARED(BLKVM,SIP/Allstream-0000d7cc)=”) in new stack
[2019-10-29 10:21:43] VERBOSE[24261] pbx.c: – Executing [[email protected]:2] Set(“SIP/248-0000d7d8”, “GOSUB_RETVAL=”) in new stack
[2019-10-29 10:21:43] VERBOSE[24261] pbx.c: – Executing [[email protected]:3] MacroExit(“SIP/248-0000d7d8”, “”) in new stack
[2019-10-29 10:21:43] VERBOSE[24261] pbx.c: – Executing [[email protected]:3] ExecIf(“SIP/248-0000d7d8”, “0?Set(MASTER_CHANNEL(CONNECTEDLINE(num))=248)”) in new stack
[2019-10-29 10:21:43] VERBOSE[24261] pbx.c: – Executing [[email protected]:4] ExecIf(“SIP/248-0000d7d8”, “0?Set(MASTER_CHANNEL(CONNECTEDLINE(name))=SACEcole1)”) in new stack
[2019-10-29 10:21:43] VERBOSE[24261] res_musiconhold.c: – Started music on hold, class ‘default’, on Local/[email protected];2
[2019-10-29 10:21:46] VERBOSE[24261] app_macro.c: == Spawn extension (from-internal-xfer, 273, 1) exited non-zero on ‘Local/[email protected];2’ in macro ‘dial-one’
[2019-10-29 10:21:46] VERBOSE[24261] app_macro.c: == Spawn extension (from-internal-xfer, 273, 1) exited non-zero on ‘Local/[email protected];2’ in macro ‘exten-vm’
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: == Spawn extension (from-internal-xfer, 273, 1) exited non-zero on ‘Local/[email protected];2’
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:1] Set(“Local/[email protected];2”, “__RINGTIMER=15”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:2] Macro(“Local/[email protected];2”, “exten-vm,273,273,0,0,0”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:1] Macro(“Local/[email protected];2”, “user-callerid,”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:1] Set(“Local/[email protected];2”, “AMPUSER=4388880916”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:2] GotoIf(“Local/[email protected];2”, “1?report”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Goto (macro-user-callerid,s,12)
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:12] GotoIf(“Local/[email protected];2”, “0?continue”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:13] Set(“Local/[email protected];2”, “__TTL=62”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:14] GotoIf(“Local/[email protected];2”, “1?continue”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Goto (macro-user-callerid,s,25)
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:25] Set(“Local/[email protected];2”, “CALLERID(number)=4388880916”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:26] Set(“Local/[email protected];2”, “CALLERID(name)=NC-4388880916”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:27] Set(“Local/[email protected];2”, “CHANNEL(language)=fr”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:2] Set(“Local/[email protected];2”, “RingGroupMethod=none”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:3] Set(“Local/[email protected];2”, “__EXTTOCALL=273”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:4] Set(“Local/[email protected];2”, “__PICKUPMARK=273”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:5] Set(“Local/[email protected];2”, “RT=15”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:6] Gosub(“Local/[email protected];2”, “sub-record-check,s,1(exten,273,)”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:1] GotoIf(“Local/[email protected];2”, “0?check”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:2] ResetCDR(“Local/[email protected];2”, “”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:3] GotoIf(“Local/[email protected];2”, “0?check”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:4] Set(“Local/[email protected];2”, “AUDIOHOOK_INHERIT(MixMonitor)=yes”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:5] MixMonitor(“Local/[email protected];2”, “2019/10/29/q-620-4388880916-20191029-102139-1572358809.241730.wav,a,”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:6] Set(“Local/[email protected];2”, “__MON_FMT=wav”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:7] GotoIf(“Local/[email protected];2”, “0?next”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:8] Set(“Local/[email protected];2”, “CDR(recordingfile)=q-620-4388880916-20191029-102139-1572358809.241730.wav”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:9] Return(“Local/[email protected];2”, “”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:7] GotoIf(“Local/[email protected];2”, “10?macrodial”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Goto (macro-exten-vm,s,13)
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:13] GosubIf(“Local/[email protected];2”, “0?clrheader,1()”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:14] Macro(“Local/[email protected];2”, “dial-one,15,trM(auto-blkvm),273”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:1] Set(“Local/[email protected];2”, “DEXTEN=273”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:2] Set(“Local/[email protected];2”, “DIALSTATUS_CW=”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:3] GosubIf(“Local/[email protected];2”, “0?screen,1()”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:4] GosubIf(“Local/[email protected];2”, “0?cf,1()”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:5] GotoIf(“Local/[email protected];2”, “1?skip1”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Goto (macro-dial-one,s,8)
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:8] GotoIf(“Local/[email protected];2”, “0?nodial”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:9] GotoIf(“Local/[email protected];2”, “0?continue”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:10] Set(“Local/[email protected];2”, “EXTHASCW=”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:11] GotoIf(“Local/[email protected];2”, “1?next1:cwinusebusy”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Goto (macro-dial-one,s,12)
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:12] GotoIf(“Local/[email protected];2”, “0?docfu:skip3”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Goto (macro-dial-one,s,16)
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:16] GotoIf(“Local/[email protected];2”, “1?next2:continue”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Goto (macro-dial-one,s,17)
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:17] GotoIf(“Local/[email protected];2”, “0?continue”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:18] ExecIf(“Local/[email protected];2”, “0?Set(DIALSTATUS=BUSY)”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:19] GotoIf(“Local/[email protected];2”, “0?cwinusebusy”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:20] Set(“Local/[email protected];2”, “DEXTEN=”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:21] Set(“Local/[email protected];2”, “DIALSTATUS=BUSY”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:22] Goto(“Local/[email protected]from-queue-1d5c;2”, “nodial”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Goto (macro-dial-one,s,46)
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:46] ExecIf(“Local/[email protected];2”, “0?Set(DIALSTATUS=NOANSWER)”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:47] NoOp(“Local/[email protected];2”, “Returned from dial-one with nothing to call and DIALSTATUS: BUSY”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:48] MacroExit(“Local/[email protected];2”, “”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:15] Set(“Local/[email protected];2”, “SV_DIALSTATUS=BUSY”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:16] GosubIf(“Local/[email protected];2”, “0?docfu,1()”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:17] GosubIf(“Local/[email protected];2”, “0?docfb,1()”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:18] Set(“Local/[email protected];2”, “DIALSTATUS=BUSY”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:19] ExecIf(“Local/[email protected];2”, “0?MacroExit()”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:20] GotoIf(“Local/[email protected];2”, “0?s-BUSY,1”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:21] Macro(“Local/[email protected];2”, “vm,273,BUSY,”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:1] Macro(“Local/[email protected];2”, “user-callerid,SKIPTTL”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:1] Set(“Local/[email protected];2”, “AMPUSER=4388880916”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:2] GotoIf(“Local/[email protected];2”, “1?report”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Goto (macro-user-callerid,s,12)
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:12] GotoIf(“Local/[email protected];2”, “1?continue”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Goto (macro-user-callerid,s,25)
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:25] Set(“Local/[email protected];2”, “CALLERID(number)=4388880916”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:26] Set(“Local/[email protected];2”, “CALLERID(name)=NC-4388880916”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:27] Set(“Local/[email protected];2”, “CHANNEL(language)=fr”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:2] Set(“Local/[email protected];2”, “VMGAIN=”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:3] Macro(“Local/[email protected];2”, “blkvm-check,”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:1] Set(“Local/[email protected];2”, “GOSUB_RETVAL=”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:2] ExecIf(“Local/[email protected];2”, “0?Set(GOSUB_RETVAL=TRUE)”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:3] MacroExit(“Local/[email protected];2”, “”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:4] GotoIf(“Local/[email protected]queue-1d5c;2”, “1?vmx,1”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Goto (macro-vm,vmx,1)
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:1] Set(“Local/[email protected];2”, “MEXTEN=273”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:2] Set(“Local/[email protected];2”, “MMODE=BUSY”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:3] Set(“Local/[email protected];2”, “RETVM=”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:4] Set(“Local/[email protected];2”, “MODE=busy”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:5] GotoIf(“Local/[email protected];2”, “1?chknomsg”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Goto (macro-vm,vmx,8)
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:8] GotoIf(“Local/[email protected];2”, “0?s-BUSY,1”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:9] GotoIf(“Local/[email protected];2”, “1?notdirect”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Goto (macro-vm,vmx,11)
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:11] NoOp(“Local/[email protected];2”, "Checking if ext 273 is enabled: ") in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:12] GotoIf(“Local/[email protected];2”, “1?s-BUSY,1”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Goto (macro-vm,s-BUSY,1)
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:1] NoOp(“Local/[email protected];2”, “BUSY voicemail”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:2] Macro(“Local/[email protected];2”, “get-vmcontext,273”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:1] Set(“Local/[email protected];2”, “VMCONTEXT=default”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:2] GotoIf(“Local/[email protected];2”, “0?200:300”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Goto (macro-get-vmcontext,s,300)
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:300] NoOp(“Local/[email protected];2”, “”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] pbx.c: – Executing [[email protected]:3] VoiceMail(“Local/[email protected];2”, “[email protected],b”) in new stack
[2019-10-29 10:21:46] VERBOSE[24261] file.c: – <Local/[email protected];2> Playing ‘vm-theperson.ulaw’ (language ‘fr’)
[2019-10-29 10:21:48] VERBOSE[24261] file.c: – <Local/[email protected];2> Playing ‘digits/2.ulaw’ (language ‘fr’)
[2019-10-29 10:21:48] VERBOSE[24261] file.c: – <Local/[email protected];2> Playing ‘digits/7.ulaw’ (language ‘fr’)
[2019-10-29 10:21:49] VERBOSE[24261] file.c: – <Local/[email protected];2> Playing ‘digits/3.ulaw’ (language ‘fr’)
[2019-10-29 10:21:49] VERBOSE[24261] file.c: – <Local/[email protected];2> Playing ‘vm-isonphone.ulaw’ (language ‘fr’)
[2019-10-29 10:21:51] VERBOSE[24261] file.c: – <Local/[email protected];2> Playing ‘vm-intro.ulaw’ (language ‘fr’)
[2019-10-29 10:21:58] VERBOSE[24261] file.c: – <Local/[email protected];2> Playing ‘beep.ulaw’ (language ‘fr’)
[2019-10-29 10:21:59] VERBOSE[24261] app_voicemail.c: – Recording the message
[2019-10-29 10:21:59] VERBOSE[24261] app.c: – x=0, open writing: /var/spool/asterisk/voicemail/default/273/tmp/gaCEe9 format: wav49, 0x2aaad0273e48
[2019-10-29 10:22:01] VERBOSE[24261] app.c: – User hung up
[2019-10-29 10:22:01] VERBOSE[24261] app_macro.c: == Spawn extension (macro-vm, s-BUSY, 3) exited non-zero on ‘Local/[email protected];2’ in macro ‘vm’
[2019-10-29 10:22:01] VERBOSE[24261] app_macro.c: == Spawn extension (macro-exten-vm, s, 21) exited non-zero on ‘Local/[email protected];2’ in macro ‘exten-vm’
[2019-10-29 10:22:01] VERBOSE[24261] pbx.c: == Spawn extension (from-internal-xfer, 273, 2) exited non-zero on ‘Local/[email protected];2’
[2019-10-29 10:22:01] VERBOSE[24261] pbx.c: – Executing [[email protected]:1] Macro(“Local/[email protected];2”, “hangupcall”) in new stack
[2019-10-29 10:22:01] VERBOSE[24261] pbx.c: – Executing [[email protected]:1] GotoIf(“Local/[email protected];2”, “1?theend”) in new stack
[2019-10-29 10:22:01] VERBOSE[24261] pbx.c: – Goto (macro-hangupcall,s,3)
[2019-10-29 10:22:01] VERBOSE[24261] pbx.c: – Executing [[email protected]:3] ExecIf(“Local/[email protected];2”, “0?Set(CDR(recordingfile)=)”) in new stack
[2019-10-29 10:22:01] VERBOSE[24261] pbx.c: – Executing [[email protected]:4] Hangup(“Local/[email protected];2”, “”) in new stack
[2019-10-29 10:22:01] VERBOSE[24261] app_macro.c: == Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘Local/[email protected];2’ in macro ‘hangupcall’
[2019-10-29 10:22:01] VERBOSE[24261] pbx.c: == Spawn extension (from-internal-xfer, h, 1) exited non-zero on ‘Local/[email protected];2’

PitzKey · October 29, 2019, 10:43pm

You can use pastebin

partgenius · October 30, 2019, 7:08am

Yes thats why you disable call forwarding on the queue. That way 248 cant forward calls to 273. No foward or follow me.

gsoucy · October 30, 2019, 9:49pm

We ran today with the new setting No Follow Me or Call Forward . There were 2 cases of queue calls redirected to the voicemail of ext 273.

Here is the sequence ( new events first ) where we see a call getting in the queue and ending up in the voicemail of 273:

Any other suggestion ? Should I disable the voicemail on that extension (not ideal by any means…) ?

partgenius · October 30, 2019, 10:03pm

So is only 2 an improvement? 248 is forwarding calls to 273. Is this in the phone, follow me, or freepbx call forwarding? If you shut that off you fix your problem. Freepbx might not always be able to detect when a phone is forwarding if its on the device. Like forward no answer, forward busy etc.

partgenius · October 30, 2019, 10:12pm

Freepbx 2.10 didnt have CEL so its not easy to drill into the calls easily. A bigger screen shot might help. Sometimes also if you hover above the text fields youll get more info. Dont know if that works with 2.10.

gsoucy · October 30, 2019, 11:51pm

Well, it is better then yesterday but is it a coincidence, maybe, maybe not.

Certainly, 248 has something to do with that. It seems related to when 248 put someone on hold, just a wild guess for now. I will check 248 settings in more details tomorrow .

Here is another log that shows 248 pushing a message in 273 voicemail. ( [Itzik] said to use pastebin but I am not sure what pastebin is , so here is a straight paste)

2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:1] Set("Local/[email protected];2", "QAGENT=248") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:2] Goto("Local/[email protected];2", "620,1") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Goto (from-queue,620,1)
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:1] Goto("Local/[email protected];2", "from-queue-exten-internal,248,1") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Goto (from-queue-exten-internal,248,1)
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:1] Set("Local/[email protected];2", "RingGroupMethod=none") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:2] Gosub("Local/[email protected];2", "sub-record-check,s,1(exten,248)") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:1] GotoIf("Local/[email protected];2", "1?check") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Goto (sub-record-check,s,6)
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:6] Set("Local/[email protected];2", "__MON_FMT=wav") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:7] GotoIf("Local/[email protected];2", "0?next") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:8] Set("Local/[email protected];2", "CDR(recordingfile)=q-620-5145911540-20191030-131132-1572455447.266064.wav") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:9] Return("Local/[email protected];2", "") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:3] Macro("Local/[email protected];2", "dial-one,,trM(auto-blkvm),248") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:1] Set("Local/[email protected];2", "DEXTEN=248") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:2] Set("Local/[email protected];2", "DIALSTATUS_CW=") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:3] GosubIf("Local/[email protected];2", "0?screen,1()") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:4] GosubIf("Local/[email protected];2", "0?cf,1()") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:5] GotoIf("Local/[email protected];2", "1?skip1") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Goto (macro-dial-one,s,8)
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:8] GotoIf("Local/[email protected];2", "0?nodial") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:9] GotoIf("Local/[email protected];2", "0?continue") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:10] Set("Local/[email protected];2", "EXTHASCW=") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:11] GotoIf("Local/[email protected];2", "1?next1:cwinusebusy") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Goto (macro-dial-one,s,12)
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:12] GotoIf("Local/[email protected];2", "0?docfu:skip3") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Goto (macro-dial-one,s,16)
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:16] GotoIf("Local/[email protected];2", "1?next2:continue") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Goto (macro-dial-one,s,17)
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:17] GotoIf("Local/[email protected];2", "1?continue") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Goto (macro-dial-one,s,25)
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:25] GotoIf("Local/[email protected];2", "0?nodial") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:26] GosubIf("Local/[email protected];2", "1?dstring,1():dlocal,1()") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:1] Set("Local/[email protected];2", "DSTRING=") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:2] Set("Local/[email protected];2", "DEVICES=248") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:3] ExecIf("Local/[email protected];2", "0?Return()") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:4] ExecIf("Local/[email protected];2", "0?Set(DEVICES=48)") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:5] Set("Local/[email protected];2", "LOOPCNT=1") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:6] Set("Local/[email protected];2", "ITER=1") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:7] Set("Local/[email protected];2", "THISDIAL=SIP/248") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:8] GosubIf("Local/[email protected];2", "1?zap2dahdi,1()") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:1] ExecIf("Local/[email protected];2", "0?Return()") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:2] Set("Local/[email protected];2", "NEWDIAL=") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:3] Set("Local/[email protected];2", "LOOPCNT2=1") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:4] Set("Local/[email protected];2", "ITER2=1") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:5] Set("Local/[email protected];2", "THISPART2=SIP/248") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:6] ExecIf("Local/[email protected];2", "0?Set(THISPART2=DAHDI/248)") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:7] Set("Local/[email protected];2", "NEWDIAL=SIP/248&") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:8] Set("Local/[email protected];2", "ITER2=2") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:9] GotoIf("Local/[email protected];2", "0?begin2") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:10] Set("Local/[email protected];2", "THISDIAL=SIP/248") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:11] Return("Local/[email protected];2", "") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:9] Set("Local/[email protected];2", "DSTRING=SIP/248&") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:10] Set("Local/[email protected];2", "ITER=2") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:11] GotoIf("Local/[email protected];2", "0?begin") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:12] Set("Local/[email protected];2", "DSTRING=SIP/248") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:13] Return("Local/[email protected];2", "") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:27] GotoIf("Local/[email protected];2", "0?nodial") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:28] GotoIf("Local/[email protected];2", "0?skiptrace") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:29] GosubIf("Local/[email protected];2", "1?ctset,1():ctclear,1()") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:1] Set("Local/[email protected];2", "DB(CALLTRACE/248)=5145911540") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:2] Return("Local/[email protected];2", "") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:30] Set("Local/[email protected];2", "D_OPTIONS=trM(auto-blkvm)") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:31] ExecIf("Local/[email protected];2", "1?SIPAddHeader(Alert-Info: <Triplet>)") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:32] ExecIf("Local/[email protected];2", "0?SIPAddHeader()") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:33] ExecIf("Local/[email protected];2", "1?Set(CHANNEL(musicclass)=Relax)") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:34] GosubIf("Local/[email protected];2", "0?qwait,1()") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:35] Set("Local/[email protected];2", "__CWIGNORE=TRUE") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:36] Set("Local/[email protected];2", "__KEEPCID=TRUE") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:37] GotoIf("Local/[email protected];2", "0?usegoto,1") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:38] GotoIf("Local/[email protected];2", "1?godial") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Goto (macro-dial-one,s,42)
[2019-10-30 13:12:35] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:42] Dial("Local/[email protected];2", "SIP/248,,trM(auto-blkvm)") in new stack
[2019-10-30 13:12:35] VERBOSE[17319] netsock2.c:   == Using SIP RTP TOS bits 184
[2019-10-30 13:12:35] VERBOSE[17319] netsock2.c:   == Using SIP RTP CoS mark 5
[2019-10-30 13:12:35] VERBOSE[17319] app_dial.c:     -- Called SIP/248
[2019-10-30 13:12:35] VERBOSE[17319] app_dial.c:     -- SIP/248-0000e447 is ringing
[2019-10-30 13:12:36] VERBOSE[17319] app_dial.c:     -- SIP/248-0000e447 answered Local/[email protected];2
[2019-10-30 13:12:36] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:1] Set("SIP/248-0000e447", "__MACRO_RESULT=") in new stack
[2019-10-30 13:12:36] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:2] Macro("SIP/248-0000e447", "blkvm-clr,") in new stack
[2019-10-30 13:12:36] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:1] Set("SIP/248-0000e447", "SHARED(BLKVM,SIP/Allstream-0000e440)=") in new stack
[2019-10-30 13:12:36] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:2] Set("SIP/248-0000e447", "GOSUB_RETVAL=") in new stack
[2019-10-30 13:12:36] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:3] MacroExit("SIP/248-0000e447", "") in new stack
[2019-10-30 13:12:36] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:3] ExecIf("SIP/248-0000e447", "0?Set(MASTER_CHANNEL(CONNECTEDLINE(num))=248)") in new stack
[2019-10-30 13:12:36] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:4] ExecIf("SIP/248-0000e447", "0?Set(MASTER_CHANNEL(CONNECTEDLINE(name))=SACEcole1)") in new stack
[2019-10-30 13:12:37] VERBOSE[17319] res_musiconhold.c:     -- Started music on hold, class 'default', on Local/[email protected];2
[2019-10-30 13:14:14] VERBOSE[17319] res_musiconhold.c:     -- Stopped music on hold on Local/[email protected];2
[2019-10-30 13:14:27] VERBOSE[17319] res_musiconhold.c:     -- Started music on hold, class 'default', on Local/[email protected];2
[2019-10-30 13:14:33] VERBOSE[17319] res_musiconhold.c:     -- Stopped music on hold on Local/[email protected];2
[2019-10-30 13:14:33] VERBOSE[17319] app_macro.c:   == Spawn extension (from-internal-xfer, 273, 1) exited non-zero on 'Local/[email protected];2' in macro 'dial-one'
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:   == Spawn extension (from-internal-xfer, 273, 1) exited non-zero on 'Local/[email protected];2'
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:1] Set("Local/[email protected];2", "__RINGTIMER=15") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:2] Macro("Local/[email protected];2", "exten-vm,273,273,0,0,0") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:1] Macro("Local/[email protected];2", "user-callerid,") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:1] Set("Local/[email protected];2", "AMPUSER=5145911540") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:2] GotoIf("Local/[email protected];2", "1?report") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Goto (macro-user-callerid,s,12)
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:12] GotoIf("Local/[email protected];2", "0?continue") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:13] Set("Local/[email protected];2", "__TTL=63") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:14] GotoIf("Local/[email protected];2", "1?continue") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Goto (macro-user-callerid,s,25)
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:25] Set("Local/[email protected];2", "CALLERID(number)=5145911540") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:26] Set("Local/[email protected];2", "CALLERID(name)=GA-5145911540") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:27] Set("Local/[email protected];2", "CHANNEL(language)=fr") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:2] Set("Local/[email protected];2", "RingGroupMethod=none") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:3] Set("Local/[email protected];2", "__EXTTOCALL=273") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:4] Set("Local/[email protected];2", "__PICKUPMARK=273") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:5] Set("Local/[email protected];2", "RT=15") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:6] Gosub("Local/[email protected];2", "sub-record-check,s,1(exten,273,)") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:1] GotoIf("Local/[email protected];2", "0?check") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:2] ResetCDR("Local/[email protected];2", "") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:3] GotoIf("Local/[email protected];2", "0?check") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:4] Set("Local/[email protected];2", "AUDIOHOOK_INHERIT(MixMonitor)=yes") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:5] MixMonitor("Local/[email protected];2", "2019/10/30/q-620-5145911540-20191030-131132-1572455447.266064.wav,a,") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:6] Set("Local/[email protected];2", "__MON_FMT=wav") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:7] GotoIf("Local/[email protected];2", "0?next") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:8] Set("Local/[email protected];2", "CDR(recordingfile)=q-620-5145911540-20191030-131132-1572455447.266064.wav") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:9] Return("Local/[email protected];2", "") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:7] GotoIf("Local/[email protected];2", "10?macrodial") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Goto (macro-exten-vm,s,13)
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:13] GosubIf("Local/[email protected];2", "0?clrheader,1()") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:14] Macro("Local/[email protected];2", "dial-one,15,trM(auto-blkvm),273") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:1] Set("Local/[email protected];2", "DEXTEN=273") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:2] Set("Local/[email protected];2", "DIALSTATUS_CW=") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:3] GosubIf("Local/[email protected];2", "0?screen,1()") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:4] GosubIf("Local/[email protected];2", "0?cf,1()") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:5] GotoIf("Local/[email protected];2", "1?skip1") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Goto (macro-dial-one,s,8)
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:8] GotoIf("Local/[email protected];2", "0?nodial") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:9] GotoIf("Local/[email protected];2", "0?continue") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:10] Set("Local/[email protected];2", "EXTHASCW=") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:11] GotoIf("Local/[email protected];2", "1?next1:cwinusebusy") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Goto (macro-dial-one,s,12)
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:12] GotoIf("Local/[email protected];2", "0?docfu:skip3") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Goto (macro-dial-one,s,16)
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:16] GotoIf("Local/[email protected];2", "1?next2:continue") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Goto (macro-dial-one,s,17)
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:17] GotoIf("Local/[email protected];2", "0?continue") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:18] ExecIf("Local/[email protected];2", "0?Set(DIALSTATUS=BUSY)") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:19] GotoIf("Local/[email protected];2", "0?cwinusebusy") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:20] Set("Local/[email protected];2", "DEXTEN=") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:21] Set("Local/[email protected];2", "DIALSTATUS=BUSY") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:22] Goto("Local/[email protected];2", "nodial") in new stack
[2019-10-30 13:14:33] VERBOSE[17319] pbx.c:     -- Goto (macro-dial-one,s,46)
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:46] ExecIf("Local/[email protected];2", "0?Set(DIALSTATUS=NOANSWER)") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:47] NoOp("Local/[email protected];2", "Returned from dial-one with nothing to call and DIALSTATUS: BUSY") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:48] MacroExit("Local/[email protected];2", "") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:15] Set("Local/[email protected];2", "SV_DIALSTATUS=BUSY") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:16] GosubIf("Local/[email protected];2", "0?docfu,1()") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:17] GosubIf("Local/[email protected];2", "0?docfb,1()") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:18] Set("Local/[email protected];2", "DIALSTATUS=BUSY") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:19] ExecIf("Local/[email protected];2", "0?MacroExit()") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:20] GotoIf("Local/[email protected];2", "0?s-BUSY,1") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:21] Macro("Local/[email protected];2", "vm,273,BUSY,") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:1] Macro("Local/[email protected];2", "user-callerid,SKIPTTL") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:1] Set("Local/[email protected];2", "AMPUSER=5145911540") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:2] GotoIf("Local/[email protected];2", "1?report") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Goto (macro-user-callerid,s,12)
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:12] GotoIf("Local/[email protected];2", "1?continue") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Goto (macro-user-callerid,s,25)
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:25] Set("Local/[email protected];2", "CALLERID(number)=5145911540") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:26] Set("Local/[email protected];2", "CALLERID(name)=GA-5145911540") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:27] Set("Local/[email protected];2", "CHANNEL(language)=fr") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:2] Set("Local/[email protected];2", "VMGAIN=") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:3] Macro("Local/[email protected];2", "blkvm-check,") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:1] Set("Local/[email protected];2", "GOSUB_RETVAL=") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:2] ExecIf("Local/[email protected];2", "0?Set(GOSUB_RETVAL=TRUE)") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:3] MacroExit("Local/[email protected];2", "") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:4] GotoIf("Local/[email protected];2", "1?vmx,1") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Goto (macro-vm,vmx,1)
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:1] Set("Local/[email protected];2", "MEXTEN=273") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:2] Set("Local/[email protected];2", "MMODE=BUSY") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:3] Set("Local/[email protected];2", "RETVM=") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:4] Set("Local/[email protected];2", "MODE=busy") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:5] GotoIf("Local/[email protected];2", "1?chknomsg") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Goto (macro-vm,vmx,8)
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:8] GotoIf("Local/[email protected];2", "0?s-BUSY,1") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:9] GotoIf("Local/[email protected];2", "1?notdirect") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Goto (macro-vm,vmx,11)
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:11] NoOp("Local/[email protected];2", "Checking if ext 273 is enabled: ") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:12] GotoIf("Local/[email protected];2", "1?s-BUSY,1") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Goto (macro-vm,s-BUSY,1)
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:1] NoOp("Local/[email protected];2", "BUSY voicemail") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:2] Macro("Local/[email protected];2", "get-vmcontext,273") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:1] Set("Local/[email protected];2", "VMCONTEXT=default") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:2] GotoIf("Local/[email protected];2", "0?200:300") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Goto (macro-get-vmcontext,s,300)
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:300] NoOp("Local/[email protected];2", "") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:3] VoiceMail("Local/[email protected];2", "[email protected],b") in new stack
[2019-10-30 13:14:34] VERBOSE[17319] file.c:     -- <Local/[email protected];2> Playing '/var/spool/asterisk/voicemail/default/273/temp.gsm' (language 'fr')
[2019-10-30 13:14:50] VERBOSE[17319] file.c:     -- <Local/[email protected];2> Playing 'vm-intro.ulaw' (language 'fr')
[2019-10-30 13:14:57] VERBOSE[17319] file.c:     -- <Local/[email protected];2> Playing 'beep.ulaw' (language 'fr')
[2019-10-30 13:14:57] VERBOSE[17319] app_voicemail.c:     -- Recording the message
[2019-10-30 13:14:57] VERBOSE[17319] app.c:     -- x=0, open writing:  /var/spool/asterisk/voicemail/default/273/tmp/BMwqhx format: wav49, 0x2aaac80af6b8
[2019-10-30 13:16:24] VERBOSE[17319] app.c:     -- User hung up
[2019-10-30 13:16:24] VERBOSE[17319] app_macro.c:   == Spawn extension (macro-vm, s-BUSY, 3) exited non-zero on 'Local/[email protected];2' in macro 'vm'
[2019-10-30 13:16:24] VERBOSE[17319] app_macro.c:   == Spawn extension (macro-exten-vm, s, 21) exited non-zero on 'Local/[email protected];2' in macro 'exten-vm'
[2019-10-30 13:16:24] VERBOSE[17319] pbx.c:   == Spawn extension (from-internal-xfer, 273, 2) exited non-zero on 'Local/[email protected];2'
[2019-10-30 13:16:24] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:1] Macro("Local/[email protected];2", "hangupcall") in new stack
[2019-10-30 13:16:24] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:1] GotoIf("Local/[email protected];2", "1?theend") in new stack
[2019-10-30 13:16:24] VERBOSE[17319] pbx.c:     -- Goto (macro-hangupcall,s,3)
[2019-10-30 13:16:24] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:3] ExecIf("Local/[email protected];2", "0?Set(CDR(recordingfile)=)") in new stack
[2019-10-30 13:16:24] VERBOSE[17319] pbx.c:     -- Executing [[email protected]:4] Hangup("Local/[email protected];2", "") in new stack
[2019-10-30 13:16:24] VERBOSE[17319] app_macro.c:   == Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'Local/[email protected];2' in macro 'hangupcall'
[2019-10-30 13:16:24] VERBOSE[17319] pbx.c:   == Spawn extension (from-internal-xfer, h, 1) exited non-zero on 'Local/[email protected];2'

gsoucy · November 6, 2019, 3:09am

Finally, after about 1 wk with this setting ( No Follow Me of Call Forward), I can say that this solved the problem. The other voicemail now are from legitimate internal forwards. All is good. Thank you !

system · November 13, 2019, 3:09am

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