Revisit - Extension(s) ring only once in queues before moving on

kudzuacura · September 7, 2010, 4:17pm

I’ve looked and looked and cannot seem to find any real answer for this original link:

http://www.freepbx.org/forum/freepbx/users/users-phone-rings-only-once-in-call-queue

The original forum topic points to this:

http://76.164.171.234/svn/asterisk?view=revision&revision=138694

…but I’m reluctant to try to recompile anything on a running system. It only started happening recently, and besides adding dynamic users to the queue, nothing has changed. In fact, it’s started happening on my ‘test’ queue that only has two members and hasn’t been modified at all. I’ve tried restarting actual machine as well as asterisk.

Debug is practically the same. Symptoms are:

One phone in queue rings for full 15 seconds as described in FreePBX setup. Next phone in queue rings once, and then moves on until eventually it comes back to the original ‘15 second’ phone. If original 15 second phone is in use, it rings another extension for the prescribed amount of time and then does a ‘one ring’ on the rest of the phones. Queue descriptions below.

TIA.

[700]
announce-frequency=30
announce-holdtime=yes
autofill=no
eventmemberstatus=no
eventwhencalled=no
joinempty=no
leavewhenempty=no
maxlen=0
periodic-announce-frequency=0
queue-callswaiting=queue-callswaiting
queue-thankyou=queue-thankyou
queue-thereare=queue-thereare
queue-youarenext=queue-youarenext
reportholdtime=no
retry=10
ringinuse=yes
servicelevel=60
strategy=leastrecent
timeout=15
weight=0
wrapuptime=30

[701]
announce-frequency=30
announce-holdtime=yes
autofill=no
eventmemberstatus=no
eventwhencalled=no
joinempty=no
leavewhenempty=no
maxlen=0
periodic-announce-frequency=0
queue-callswaiting=queue-callswaiting
queue-thankyou=queue-thankyou
queue-thereare=queue-thereare
queue-youarenext=queue-youarenext
reportholdtime=no
retry=10
ringinuse=yes
servicelevel=60
strategy=leastrecent
timeout=15
weight=0
wrapuptime=15

kudzuacura · September 8, 2010, 3:55pm

Somehow it appears it thinks it is ringing the ‘one ring’ extension for 15 seconds… The comments in the debug are my own typed while the stuff was happening… The queue in question (well, it’s happening on all of them) is 700…

Thanks again anyone for any help they may be able to provide…


pbx*CLI> 
pbx*CLI> 
pbx*CLI> 
pbx*CLI> show queue 700
700          has 0 calls (max unlimited) in 'leastrecent' strategy (0s holdtime), W:0, C:0, A:1, SL:0.0% within 60s
   Members: 
      David Clark 404 (Local/404@from-queue/n) (dynamic) (Not in use) has taken no calls yet
      David Clark 401 (Local/401@from-queue/n) (dynamic) (Not in use) has taken no calls yet
   No Callers

The 'show queue' command is deprecated and will be removed in a future release. Please use 'queue show' instead.
    -- Executing [6157227222@from-pstn:1] Set("SIP/fpbx-1-afa853cf-0000000d", "__FROM_DID=6157227222") in new stack
    -- Executing [6157227222@from-pstn:2] Gosub("SIP/fpbx-1-afa853cf-0000000d", "app-blacklist-check|s|1") in new stack
    -- Executing [s@app-blacklist-check:1] LookupBlacklist("SIP/fpbx-1-afa853cf-0000000d", "") in new stack
    -- Executing [s@app-blacklist-check:2] GotoIf("SIP/fpbx-1-afa853cf-0000000d", "0?blacklisted") in new stack
    -- Executing [s@app-blacklist-check:3] Set("SIP/fpbx-1-afa853cf-0000000d", "CALLED_BLACKLIST=1") in new stack
    -- Executing [s@app-blacklist-check:4] Return("SIP/fpbx-1-afa853cf-0000000d", "") in new stack
    -- Executing [6157227222@from-pstn:3] ExecIf("SIP/fpbx-1-afa853cf-0000000d", "0 |Set|CALLERID(name)=9396308533") in new stack
    -- Executing [6157227222@from-pstn:4] Set("SIP/fpbx-1-afa853cf-0000000d", "__CALLINGPRES_SV=allowed_not_screened") in new stack
    -- Executing [6157227222@from-pstn:5] SetCallerPres("SIP/fpbx-1-afa853cf-0000000d", "allowed_not_screened") in new stack
    -- Executing [6157227222@from-pstn:6] Goto("SIP/fpbx-1-afa853cf-0000000d", "app-daynight|1|1") in new stack
    -- Goto (app-daynight,1,1)
    -- Executing [1@app-daynight:1] GotoIf("SIP/fpbx-1-afa853cf-0000000d", "1?ext-queues|799|1:ext-queues|701|1") in new stack
    -- Goto (ext-queues,799,1)
    -- Executing [799@ext-queues:1] Macro("SIP/fpbx-1-afa853cf-0000000d", "user-callerid|") in new stack
    -- Executing [s@macro-user-callerid:1] Set("SIP/fpbx-1-afa853cf-0000000d", "AMPUSER=9396308533") in new stack
    -- Executing [s@macro-user-callerid:2] GotoIf("SIP/fpbx-1-afa853cf-0000000d", "0?report") in new stack
    -- Executing [s@macro-user-callerid:3] ExecIf("SIP/fpbx-1-afa853cf-0000000d", "1|Set|REALCALLERIDNUM=9396308533") in new stack
    -- Executing [s@macro-user-callerid:4] Set("SIP/fpbx-1-afa853cf-0000000d", "AMPUSER=") in new stack
    -- Executing [s@macro-user-callerid:5] Set("SIP/fpbx-1-afa853cf-0000000d", "AMPUSERCIDNAME=") in new stack
    -- Executing [s@macro-user-callerid:6] GotoIf("SIP/fpbx-1-afa853cf-0000000d", "1?report") in new stack
    -- Goto (macro-user-callerid,s,9)
    -- Executing [s@macro-user-callerid:9] GotoIf("SIP/fpbx-1-afa853cf-0000000d", "0?continue") in new stack
    -- Executing [s@macro-user-callerid:10] Set("SIP/fpbx-1-afa853cf-0000000d", "__TTL=64") in new stack
    -- Executing [s@macro-user-callerid:11] GotoIf("SIP/fpbx-1-afa853cf-0000000d", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,18)
    -- Executing [s@macro-user-callerid:18] NoOp("SIP/fpbx-1-afa853cf-0000000d", "Using CallerID "Unavailable " <9396308533>") in new stack
    -- Executing [799@ext-queues:2] Answer("SIP/fpbx-1-afa853cf-0000000d", "") in new stack
    -- Executing [799@ext-queues:3] Set("SIP/fpbx-1-afa853cf-0000000d", "__BLKVM_OVERRIDE=BLKVM/799/SIP/fpbx-1-afa853cf-0000000d") in new stack
    -- Executing [799@ext-queues:4] Set("SIP/fpbx-1-afa853cf-0000000d", "__BLKVM_BASE=799") in new stack
    -- Executing [799@ext-queues:5] Set("SIP/fpbx-1-afa853cf-0000000d", "DB(BLKVM/799/SIP/fpbx-1-afa853cf-0000000d)=TRUE") in new stack
    -- Executing [799@ext-queues:6] ExecIf("SIP/fpbx-1-afa853cf-0000000d", "1|Set|_DIAL_OPTIONS=trwWM(auto-blkvm)") in new stack
    -- Executing [799@ext-queues:7] Set("SIP/fpbx-1-afa853cf-0000000d", "__NODEST=799") in new stack
    -- Executing [799@ext-queues:8] Set("SIP/fpbx-1-afa853cf-0000000d", "MONITOR_FILENAME=/var/spool/asterisk/monitor/q799-20100908-104523-1283960723.21") in new stack
    -- Executing [799@ext-queues:9] Playback("SIP/fpbx-1-afa853cf-0000000d", "custom/NationalGuardVMail") in new stack
    -- <SIP/fpbx-1-afa853cf-0000000d> Playing 'custom/NationalGuardVMail' (language 'en')
  == Spawn extension (ext-queues, 799, 9) exited non-zero on 'SIP/fpbx-1-afa853cf-0000000d'
pbx*CLI> 
pbx*CLI> 
pbx*CLI> 
pbx*CLI> 
pbx*CLI> 
pbx*CLI> 
pbx*CLI> 
pbx*CLI> 
pbx*CLI> 
pbx*CLI> 
pbx*CLI> 
pbx*CLI> 
pbx*CLI> 
pbx*CLI> 
    -- Executing [6157227228@from-pstn:1] Set("SIP/fpbx-1-afa853cf-0000000e", "__FROM_DID=6157227228") in new stack
    -- Executing [6157227228@from-pstn:2] Gosub("SIP/fpbx-1-afa853cf-0000000e", "app-blacklist-check|s|1") in new stack
    -- Executing [s@app-blacklist-check:1] LookupBlacklist("SIP/fpbx-1-afa853cf-0000000e", "") in new stack
    -- Executing [s@app-blacklist-check:2] GotoIf("SIP/fpbx-1-afa853cf-0000000e", "0?blacklisted") in new stack
    -- Executing [s@app-blacklist-check:3] Set("SIP/fpbx-1-afa853cf-0000000e", "CALLED_BLACKLIST=1") in new stack
    -- Executing [s@app-blacklist-check:4] Return("SIP/fpbx-1-afa853cf-0000000e", "") in new stack
    -- Executing [6157227228@from-pstn:3] ExecIf("SIP/fpbx-1-afa853cf-0000000e", "0 |Set|CALLERID(name)=6157244200") in new stack
    -- Executing [6157227228@from-pstn:4] Set("SIP/fpbx-1-afa853cf-0000000e", "__CALLINGPRES_SV=allowed_not_screened") in new stack
    -- Executing [6157227228@from-pstn:5] SetCallerPres("SIP/fpbx-1-afa853cf-0000000e", "allowed_not_screened") in new stack
    -- Executing [6157227228@from-pstn:6] Goto("SIP/fpbx-1-afa853cf-0000000e", "ext-queues|700|1") in new stack
    -- Goto (ext-queues,700,1)
    -- Executing [700@ext-queues:1] Macro("SIP/fpbx-1-afa853cf-0000000e", "user-callerid|") in new stack
    -- Executing [s@macro-user-callerid:1] Set("SIP/fpbx-1-afa853cf-0000000e", "AMPUSER=6157244200") in new stack
    -- Executing [s@macro-user-callerid:2] GotoIf("SIP/fpbx-1-afa853cf-0000000e", "0?report") in new stack
    -- Executing [s@macro-user-callerid:3] ExecIf("SIP/fpbx-1-afa853cf-0000000e", "1|Set|REALCALLERIDNUM=6157244200") in new stack
    -- Executing [s@macro-user-callerid:4] Set("SIP/fpbx-1-afa853cf-0000000e", "AMPUSER=") in new stack
    -- Executing [s@macro-user-callerid:5] Set("SIP/fpbx-1-afa853cf-0000000e", "AMPUSERCIDNAME=") in new stack
    -- Executing [s@macro-user-callerid:6] GotoIf("SIP/fpbx-1-afa853cf-0000000e", "1?report") in new stack
    -- Goto (macro-user-callerid,s,9)
    -- Executing [s@macro-user-callerid:9] GotoIf("SIP/fpbx-1-afa853cf-0000000e", "0?continue") in new stack
    -- Executing [s@macro-user-callerid:10] Set("SIP/fpbx-1-afa853cf-0000000e", "__TTL=64") in new stack
    -- Executing [s@macro-user-callerid:11] GotoIf("SIP/fpbx-1-afa853cf-0000000e", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,18)
    -- Executing [s@macro-user-callerid:18] NoOp("SIP/fpbx-1-afa853cf-0000000e", "Using CallerID "Private " <6157244200>") in new stack
    -- Executing [700@ext-queues:2] Answer("SIP/fpbx-1-afa853cf-0000000e", "") in new stack
    -- Executing [700@ext-queues:3] Set("SIP/fpbx-1-afa853cf-0000000e", "__BLKVM_OVERRIDE=BLKVM/700/SIP/fpbx-1-afa853cf-0000000e") in new stack
    -- Executing [700@ext-queues:4] Set("SIP/fpbx-1-afa853cf-0000000e", "__BLKVM_BASE=700") in new stack
    -- Executing [700@ext-queues:5] Set("SIP/fpbx-1-afa853cf-0000000e", "DB(BLKVM/700/SIP/fpbx-1-afa853cf-0000000e)=TRUE") in new stack
    -- Executing [700@ext-queues:6] ExecIf("SIP/fpbx-1-afa853cf-0000000e", "1|Set|_DIAL_OPTIONS=trwWM(auto-blkvm)") in new stack
    -- Executing [700@ext-queues:7] Set("SIP/fpbx-1-afa853cf-0000000e", "__NODEST=700") in new stack
    -- Executing [700@ext-queues:8] Set("SIP/fpbx-1-afa853cf-0000000e", "MONITOR_FILENAME=/var/spool/asterisk/monitor/q700-20100908-104537-1283960737.22") in new stack
    -- Executing [700@ext-queues:9] Playback("SIP/fpbx-1-afa853cf-0000000e", "custom/TYCallNG") in new stack
    -- <SIP/fpbx-1-afa853cf-0000000e> Playing 'custom/TYCallNG' (language 'en')
pbx*CLI> 
    -- Executing [700@ext-queues:10] Set("SIP/fpbx-1-afa853cf-0000000e", "__CWIGNORE=TRUE") in new stack
    -- Executing [700@ext-queues:11] Queue("SIP/fpbx-1-afa853cf-0000000e", "700|t||") in new stack
    -- Started music on hold, class 'default', on SIP/fpbx-1-afa853cf-0000000e
    -- Executing [401@from-queue:1] Set("Local/401@from-queue-d81a,2", "QAGENT=401") in new stack
    -- Executing [401@from-queue:2] Goto("Local/401@from-queue-d81a,2", "700|1") in new stack
    -- Goto (from-queue,700,1)
    -- Executing [700@from-queue:1] Goto("Local/401@from-queue-d81a,2", "from-internal|401|1") in new stack
    -- Goto (from-internal,401,1)
    -- Executing [401@from-internal:1] Macro("Local/401@from-queue-d81a,2", "exten-vm|401|401") in new stack
    -- Executing [s@macro-exten-vm:1] Macro("Local/401@from-queue-d81a,2", "user-callerid|") in new stack
    -- Executing [s@macro-user-callerid:1] Set("Local/401@from-queue-d81a,2", "AMPUSER=6157244200") in new stack
    -- Executing [s@macro-user-callerid:2] GotoIf("Local/401@from-queue-d81a,2", "1?report") in new stack
    -- Goto (macro-user-callerid,s,9)
    -- Executing [s@macro-user-callerid:9] GotoIf("Local/401@from-queue-d81a,2", "0?continue") in new stack
    -- Executing [s@macro-user-callerid:10] Set("Local/401@from-queue-d81a,2", "__TTL=63") in new stack
    -- Executing [s@macro-user-callerid:11] GotoIf("Local/401@from-queue-d81a,2", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,18)
    -- Executing [s@macro-user-callerid:18] NoOp("Local/401@from-queue-d81a,2", "Using CallerID "Private " <6157244200>") in new stack
    -- Executing [s@macro-exten-vm:2] Set("Local/401@from-queue-d81a,2", "RingGroupMethod=none") in new stack
    -- Executing [s@macro-exten-vm:3] Set("Local/401@from-queue-d81a,2", "VMBOX=401") in new stack
    -- Executing [s@macro-exten-vm:4] Set("Local/401@from-queue-d81a,2", "__EXTTOCALL=401") in new stack
    -- Executing [s@macro-exten-vm:5] Set("Local/401@from-queue-d81a,2", "CFUEXT=") in new stack
    -- Executing [s@macro-exten-vm:6] Set("Local/401@from-queue-d81a,2", "CFBEXT=") in new stack
    -- Executing [s@macro-exten-vm:7] Set("Local/401@from-queue-d81a,2", "RT=15") in new stack
    -- Executing [s@macro-exten-vm:8] Macro("Local/401@from-queue-d81a,2", "record-enable|401|IN") in new stack
    -- Executing [s@macro-record-enable:1] GotoIf("Local/401@from-queue-d81a,2", "1?check") in new stack
    -- Goto (macro-record-enable,s,4)
    -- Executing [s@macro-record-enable:4] ExecIf("Local/401@from-queue-d81a,2", "0|MacroExit|") in new stack
    -- Executing [s@macro-record-enable:5] GotoIf("Local/401@from-queue-d81a,2", "0?Group:OUT") in new stack
    -- Goto (macro-record-enable,s,15)
    -- Executing [s@macro-record-enable:15] GotoIf("Local/401@from-queue-d81a,2", "1?IN") in new stack
    -- Goto (macro-record-enable,s,20)
    -- Executing [s@macro-record-enable:20] ExecIf("Local/401@from-queue-d81a,2", "1|MacroExit|") in new stack
    -- Executing [s@macro-exten-vm:9] Macro("Local/401@from-queue-d81a,2", "dial|15|trwWM(auto-blkvm)|401") in new stack
    -- Executing [s@macro-dial:1] GotoIf("Local/401@from-queue-d81a,2", "1?dial") in new stack
    -- Goto (macro-dial,s,3)
    -- Executing [s@macro-dial:3] AGI("Local/401@from-queue-d81a,2", "dialparties.agi") in new stack
    -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
  dialparties.agi: Starting New Dialparties.agi
  == Parsing '/etc/asterisk/manager.conf': Found
  == Parsing '/etc/asterisk/manager_additional.conf': Found
  == Parsing '/etc/asterisk/manager_custom.conf': Found
  == Manager 'admin' logged on from 127.0.0.1
  dialparties.agi: Caller ID name is 'Private' number is '6157244200'
  dialparties.agi: USE_CONFIRMATION:  'FALSE'
  dialparties.agi: RINGGROUP_INDEX:   ''
  dialparties.agi: Methodology of ring is  'none'
    --  dialparties.agi: Added extension 401 to extension map
    --  dialparties.agi: Extension 401 cf is disabled
    --  dialparties.agi: Extension 401 do not disturb is disabled
       >  dialparties.agi: extnum 401 has:  cw: 0; hascfb: 0 [] hascfu: 0 []
  dialparties.agi: ExtensionState: 0
  dialparties.agi: Extension 401 has ExtensionState: 0
    --  dialparties.agi: Checking CW and CFB status for extension 401
    --  dialparties.agi: dbset CALLTRACE/401 to 6157244200
    --  dialparties.agi: Filtered ARG3: 401
       >  dialparties.agi: NODEST: 700 blkvm enabled macro already in dialopts: trwWM(auto-blkvm)
       >  dialparties.agi: NODEST: 700 blkvm enabled macro already in dialopts: trwWM(auto-blkvm)
  == Manager 'admin' logged off from 127.0.0.1
    -- AGI Script dialparties.agi completed, returning 0
    -- Executing [s@macro-dial:7] Dial("Local/401@from-queue-d81a,2", "SIP/401|15|trwWM(auto-blkvm)") in new stack
    -- Called 401
    -- Local/401@from-queue-d81a,1 is ringing
pbx*CLI> 
pbx*CLI> 
pbx*CLI> 
    -- SIP/401-0000000f is ringing
pbx*CLI> 
pbx*CLI> 
pbx*CLI> 
pbx*CLI> 
pbx*CLI> 
pbx*CLI> 
    -- Nobody picked up in 15000 ms
    -- Executing [s@macro-dial:8] Set("Local/401@from-queue-d81a,2", "DIALSTATUS=NOANSWER") in new stack
    -- Executing [s@macro-dial:9] GosubIf("Local/401@from-queue-d81a,2", "0?NOANSWER|1") in new stack
    -- Executing [s@macro-exten-vm:10] GotoIf("Local/401@from-queue-d81a,2", "0?exit|return") in new stack
    -- Executing [s@macro-exten-vm:11] Set("Local/401@from-queue-d81a,2", "SV_DIALSTATUS=NOANSWER") in new stack
    -- Executing [s@macro-exten-vm:12] GosubIf("Local/401@from-queue-d81a,2", "0?docfu|1") in new stack
    -- Executing [s@macro-exten-vm:13] GosubIf("Local/401@from-queue-d81a,2", "0?docfb|1") in new stack
    -- Executing [s@macro-exten-vm:14] Set("Local/401@from-queue-d81a,2", "DIALSTATUS=NOANSWER") in new stack
    -- Executing [s@macro-exten-vm:15] NoOp("Local/401@from-queue-d81a,2", "Voicemail is 401") in new stack
    -- Executing [s@macro-exten-vm:16] GotoIf("Local/401@from-queue-d81a,2", "0?s-NOANSWER|1") in new stack
    -- Executing [s@macro-exten-vm:17] NoOp("Local/401@from-queue-d81a,2", "Sending to Voicemail box 401") in new stack
    -- Executing [s@macro-exten-vm:18] Macro("Local/401@from-queue-d81a,2", "vm|401|NOANSWER|") in new stack
    -- Executing [s@macro-vm:1] Macro("Local/401@from-queue-d81a,2", "user-callerid|SKIPTTL") in new stack
    -- Executing [s@macro-user-callerid:1] Set("Local/401@from-queue-d81a,2", "AMPUSER=6157244200") in new stack
    -- Executing [s@macro-user-callerid:2] GotoIf("Local/401@from-queue-d81a,2", "1?report") in new stack
    -- Goto (macro-user-callerid,s,9)
    -- Executing [s@macro-user-callerid:9] GotoIf("Local/401@from-queue-d81a,2", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,18)
    -- Executing [s@macro-user-callerid:18] NoOp("Local/401@from-queue-d81a,2", "Using CallerID "Private " <6157244200>") in new stack
    -- Executing [s@macro-vm:2] Set("Local/401@from-queue-d81a,2", "VMGAIN=""") in new stack
    -- Executing [s@macro-vm:3] GotoIf("Local/401@from-queue-d81a,2", "0?vmx|1") in new stack
    -- Executing [s@macro-vm:4] NoOp("Local/401@from-queue-d81a,2", "CAME FROM: 700 - Blocking VM cause of key: ") in new stack
    -- Executing [s@macro-vm:5] Hangup("Local/401@from-queue-d81a,2", "") in new stack
  == Spawn extension (macro-vm, s, 5) exited non-zero on 'Local/401@from-queue-d81a,2' in macro 'vm'
  == Spawn extension (macro-exten-vm, s, 18) exited non-zero on 'Local/401@from-queue-d81a,2' in macro 'exten-vm'
  == Spawn extension (from-internal, 401, 1) exited non-zero on 'Local/401@from-queue-d81a,2'
    -- Executing [h@from-internal:1] Macro("Local/401@from-queue-d81a,2", "hangupcall") in new stack
    -- Executing [s@macro-hangupcall:1] GotoIf("Local/401@from-queue-d81a,2", "1?skiprg") in new stack
    -- Goto (macro-hangupcall,s,4)
    -- Executing [s@macro-hangupcall:4] GotoIf("Local/401@from-queue-d81a,2", "1?skipblkvm") in new stack
    -- Goto (macro-hangupcall,s,7)
    -- Executing [s@macro-hangupcall:7] GotoIf("Local/401@from-queue-d81a,2", "1?theend") in new stack
    -- Goto (macro-hangupcall,s,9)
    -- Executing [s@macro-hangupcall:9] Hangup("Local/401@from-queue-d81a,2", "") in new stack
  == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'Local/401@from-queue-d81a,2' in macro 'hangupcall'
  == Spawn extension (from-internal, h, 1) exited non-zero on 'Local/401@from-queue-d81a,2'
    -- Nobody picked up in 15000 ms
    -- Executing [404@from-queue:1] Set("Local/404@from-queue-6c72,2", "QAGENT=404") in new stack
    -- Executing [404@from-queue:2] Goto("Local/404@from-queue-6c72,2", "700|1") in new stack
    -- Goto (from-queue,700,1)
    -- Executing [700@from-queue:1] Goto("Local/404@from-queue-6c72,2", "from-internal|404|1") in new stack
    -- Goto (from-internal,404,1)
    -- Executing [404@from-internal:1] Macro("Local/404@from-queue-6c72,2", "exten-vm|404|404") in new stack
    -- Executing [s@macro-exten-vm:1] Macro("Local/404@from-queue-6c72,2", "user-callerid|") in new stack
    -- Executing [s@macro-user-callerid:1] Set("Local/404@from-queue-6c72,2", "AMPUSER=6157244200") in new stack
    -- Executing [s@macro-user-callerid:2] GotoIf("Local/404@from-queue-6c72,2", "1?report") in new stack
    -- Goto (macro-user-callerid,s,9)
    -- Executing [s@macro-user-callerid:9] GotoIf("Local/404@from-queue-6c72,2", "0?continue") in new stack
    -- Executing [s@macro-user-callerid:10] Set("Local/404@from-queue-6c72,2", "__TTL=63") in new stack
    -- Executing [s@macro-user-callerid:11] GotoIf("Local/404@from-queue-6c72,2", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,18)
    -- Executing [s@macro-user-callerid:18] NoOp("Local/404@from-queue-6c72,2", "Using CallerID "Private " <6157244200>") in new stack
    -- Executing [s@macro-exten-vm:2] Set("Local/404@from-queue-6c72,2", "RingGroupMethod=none") in new stack
    -- Executing [s@macro-exten-vm:3] Set("Local/404@from-queue-6c72,2", "VMBOX=404") in new stack
    -- Executing [s@macro-exten-vm:4] Set("Local/404@from-queue-6c72,2", "__EXTTOCALL=404") in new stack
    -- Executing [s@macro-exten-vm:5] Set("Local/404@from-queue-6c72,2", "CFUEXT=") in new stack
    -- Executing [s@macro-exten-vm:6] Set("Local/404@from-queue-6c72,2", "CFBEXT=") in new stack
    -- Executing [s@macro-exten-vm:7] Set("Local/404@from-queue-6c72,2", "RT=15") in new stack
    -- Executing [s@macro-exten-vm:8] Macro("Local/404@from-queue-6c72,2", "record-enable|404|IN") in new stack
    -- Executing [s@macro-record-enable:1] GotoIf("Local/404@from-queue-6c72,2", "1?check") in new stack
    -- Goto (macro-record-enable,s,4)
    -- Executing [s@macro-record-enable:4] ExecIf("Local/404@from-queue-6c72,2", "0|MacroExit|") in new stack
    -- Executing [s@macro-record-enable:5] GotoIf("Local/404@from-queue-6c72,2", "0?Group:OUT") in new stack
    -- Goto (macro-record-enable,s,15)
    -- Executing [s@macro-record-enable:15] GotoIf("Local/404@from-queue-6c72,2", "1?IN") in new stack
    -- Goto (macro-record-enable,s,20)
    -- Executing [s@macro-record-enable:20] ExecIf("Local/404@from-queue-6c72,2", "1|MacroExit|") in new stack
    -- Executing [s@macro-exten-vm:9] Macro("Local/404@from-queue-6c72,2", "dial|15|trwWM(auto-blkvm)|404") in new stack
    -- Executing [s@macro-dial:1] GotoIf("Local/404@from-queue-6c72,2", "1?dial") in new stack
    -- Goto (macro-dial,s,3)
    -- Executing [s@macro-dial:3] AGI("Local/404@from-queue-6c72,2", "dialparties.agi") in new stack
    -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
  dialparties.agi: Starting New Dialparties.agi
  == Parsing '/etc/asterisk/manager.conf': Found
  == Parsing '/etc/asterisk/manager_additional.conf': Found
  == Parsing '/etc/asterisk/manager_custom.conf': Found
  == Manager 'admin' logged on from 127.0.0.1
  dialparties.agi: Caller ID name is 'Private' number is '6157244200'
  dialparties.agi: USE_CONFIRMATION:  'FALSE'
  dialparties.agi: RINGGROUP_INDEX:   ''
  dialparties.agi: Methodology of ring is  'none'
    --  dialparties.agi: Added extension 404 to extension map
    --  dialparties.agi: Extension 404 cf is disabled
    --  dialparties.agi: Extension 404 do not disturb is disabled
       >  dialparties.agi: extnum 404 has:  cw: 0; hascfb: 0 [] hascfu: 0 []
  dialparties.agi: ExtensionState: 0
  dialparties.agi: Extension 404 has ExtensionState: 0
    --  dialparties.agi: Checking CW and CFB status for extension 404
    --  dialparties.agi: dbset CALLTRACE/404 to 6157244200
    --  dialparties.agi: Filtered ARG3: 404
       >  dialparties.agi: NODEST: 700 blkvm enabled macro already in dialopts: trwWM(auto-blkvm)
       >  dialparties.agi: NODEST: 700 blkvm enabled macro already in dialopts: trwWM(auto-blkvm)
  == Manager 'admin' logged off from 127.0.0.1
    -- AGI Script dialparties.agi completed, returning 0
    -- Executing [s@macro-dial:7] Dial("Local/404@from-queue-6c72,2", "SIP/404|15|trwWM(auto-blkvm)") in new stack
    -- Called 404
    -- Local/404@from-queue-6c72,1 is ringing
    -- SIP/404-00000010 is ringing
    -- SIP/404-00000010 is ringing
    -- Nobody picked up in 15000 ms
  == Spawn extension (macro-dial, s, 7) exited non-zero on 'Local/404@from-queue-6c72,2' in macro 'dial'
  == Spawn extension (macro-exten-vm, s, 9) exited non-zero on 'Local/404@from-queue-6c72,2' in macro 'exten-vm'
  == Spawn extension (from-internal, 404, 1) exited non-zero on 'Local/404@from-queue-6c72,2'
    -- Executing [h@macro-dial:1] Macro("Local/404@from-queue-6c72,2", "hangupcall") in new stack
    -- Executing [s@macro-hangupcall:1] GotoIf("Local/404@from-queue-6c72,2", "1?skiprg") in new stack
    -- Goto (macro-hangupcall,s,4)
    -- Executing [s@macro-hangupcall:4] GotoIf("Local/404@from-queue-6c72,2", "1?skipblkvm") in new stack
    -- Goto (macro-hangupcall,s,7)
    -- Executing [s@macro-hangupcall:7] GotoIf("Local/404@from-queue-6c72,2", "1?theend") in new stack
    -- Goto (macro-hangupcall,s,9)
    -- Executing [s@macro-hangupcall:9] Hangup("Local/404@from-queue-6c72,2", "") in new stack
  == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'Local/404@from-queue-6c72,2' in macro 'hangupcall'
  == Spawn extension (macro-dial, h, 1) exited non-zero on 'Local/404@from-queue-6c72,2'
pbx*CLI> 
pbx*CLI> 
pbx*CLI> 
pbx*CLI> 
pbx*CLI> 
pbx*CLI> 
pbx*CLI> waiting
No such command 'waiting' (type 'help waiting' for other possible commands)
pbx*CLI> 
pbx*CLI> 
    -- Stopped music on hold on SIP/fpbx-1-afa853cf-0000000e
    -- <SIP/fpbx-1-afa853cf-0000000e> Playing 'queue-youarenext' (language 'en')
    -- Told SIP/fpbx-1-afa853cf-0000000e in 700 their queue position (which was 1)
    -- <SIP/fpbx-1-afa853cf-0000000e> Playing 'queue-thankyou' (language 'en')
    -- Started music on hold, class 'default', on SIP/fpbx-1-afa853cf-0000000e
    -- Executing [401@from-queue:1] Set("Local/401@from-queue-eded,2", "QAGENT=401") in new stack
    -- Executing [401@from-queue:2] Goto("Local/401@from-queue-eded,2", "700|1") in new stack
    -- Goto (from-queue,700,1)
    -- Executing [700@from-queue:1] Goto("Local/401@from-queue-eded,2", "from-internal|401|1") in new stack
    -- Goto (from-internal,401,1)
    -- Executing [401@from-internal:1] Macro("Local/401@from-queue-eded,2", "exten-vm|401|401") in new stack
    -- Executing [s@macro-exten-vm:1] Macro("Local/401@from-queue-eded,2", "user-callerid|") in new stack
    -- Executing [s@macro-user-callerid:1] Set("Local/401@from-queue-eded,2", "AMPUSER=6157244200") in new stack
    -- Executing [s@macro-user-callerid:2] GotoIf("Local/401@from-queue-eded,2", "1?report") in new stack
    -- Goto (macro-user-callerid,s,9)
    -- Executing [s@macro-user-callerid:9] GotoIf("Local/401@from-queue-eded,2", "0?continue") in new stack
    -- Executing [s@macro-user-callerid:10] Set("Local/401@from-queue-eded,2", "__TTL=63") in new stack
    -- Executing [s@macro-user-callerid:11] GotoIf("Local/401@from-queue-eded,2", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,18)
    -- Executing [s@macro-user-callerid:18] NoOp("Local/401@from-queue-eded,2", "Using CallerID "Private " <6157244200>") in new stack
    -- Executing [s@macro-exten-vm:2] Set("Local/401@from-queue-eded,2", "RingGroupMethod=none") in new stack
    -- Executing [s@macro-exten-vm:3] Set("Local/401@from-queue-eded,2", "VMBOX=401") in new stack
    -- Executing [s@macro-exten-vm:4] Set("Local/401@from-queue-eded,2", "__EXTTOCALL=401") in new stack
    -- Executing [s@macro-exten-vm:5] Set("Local/401@from-queue-eded,2", "CFUEXT=") in new stack
    -- Executing [s@macro-exten-vm:6] Set("Local/401@from-queue-eded,2", "CFBEXT=") in new stack
    -- Executing [s@macro-exten-vm:7] Set("Local/401@from-queue-eded,2", "RT=15") in new stack
    -- Executing [s@macro-exten-vm:8] Macro("Local/401@from-queue-eded,2", "record-enable|401|IN") in new stack
    -- Executing [s@macro-record-enable:1] GotoIf("Local/401@from-queue-eded,2", "1?check") in new stack
    -- Goto (macro-record-enable,s,4)
    -- Executing [s@macro-record-enable:4] ExecIf("Local/401@from-queue-eded,2", "0|MacroExit|") in new stack
    -- Executing [s@macro-record-enable:5] GotoIf("Local/401@from-queue-eded,2", "0?Group:OUT") in new stack
    -- Goto (macro-record-enable,s,15)
    -- Executing [s@macro-record-enable:15] GotoIf("Local/401@from-queue-eded,2", "1?IN") in new stack
    -- Goto (macro-record-enable,s,20)
    -- Executing [s@macro-record-enable:20] ExecIf("Local/401@from-queue-eded,2", "1|MacroExit|") in new stack
    -- Executing [s@macro-exten-vm:9] Macro("Local/401@from-queue-eded,2", "dial|15|trwWM(auto-blkvm)|401") in new stack
    -- Executing [s@macro-dial:1] GotoIf("Local/401@from-queue-eded,2", "1?dial") in new stack
    -- Goto (macro-dial,s,3)
    -- Executing [s@macro-dial:3] AGI("Local/401@from-queue-eded,2", "dialparties.agi") in new stack
    -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
  dialparties.agi: Starting New Dialparties.agi
  == Parsing '/etc/asterisk/manager.conf': Found
  == Parsing '/etc/asterisk/manager_additional.conf': Found
  == Parsing '/etc/asterisk/manager_custom.conf': Found
  == Manager 'admin' logged on from 127.0.0.1
  dialparties.agi: Caller ID name is 'Private' number is '6157244200'
  dialparties.agi: USE_CONFIRMATION:  'FALSE'
  dialparties.agi: RINGGROUP_INDEX:   ''
  dialparties.agi: Methodology of ring is  'none'
    --  dialparties.agi: Added extension 401 to extension map
    --  dialparties.agi: Extension 401 cf is disabled
    --  dialparties.agi: Extension 401 do not disturb is disabled
       >  dialparties.agi: extnum 401 has:  cw: 0; hascfb: 0 [] hascfu: 0 []
  dialparties.agi: ExtensionState: 0
  dialparties.agi: Extension 401 has ExtensionState: 0
    --  dialparties.agi: Checking CW and CFB status for extension 401
    --  dialparties.agi: dbset CALLTRACE/401 to 6157244200
    --  dialparties.agi: Filtered ARG3: 401
       >  dialparties.agi: NODEST: 700 blkvm enabled macro already in dialopts: trwWM(auto-blkvm)
       >  dialparties.agi: NODEST: 700 blkvm enabled macro already in dialopts: trwWM(auto-blkvm)
  == Manager 'admin' logged off from 127.0.0.1
    -- AGI Script dialparties.agi completed, returning 0
    -- Executing [s@macro-dial:7] Dial("Local/401@from-queue-eded,2", "SIP/401|15|trwWM(auto-blkvm)") in new stack
    -- Called 401
    -- Local/401@from-queue-eded,1 is ringing
    -- SIP/401-00000011 is ringing
pbx*CLI> 
pbx*CLI> 
pbx*CLI> back to first extension
No such command 'back to first extension' (type 'help back to' for other possible commands)
pbx*CLI> 
pbx*CLI> 
pbx*CLI> 
pbx*CLI> 
    -- Nobody picked up in 15000 ms
    -- Executing [s@macro-dial:8] Set("Local/401@from-queue-eded,2", "DIALSTATUS=NOANSWER") in new stack
    -- Executing [s@macro-dial:9] GosubIf("Local/401@from-queue-eded,2", "0?NOANSWER|1") in new stack
    -- Executing [s@macro-exten-vm:10] GotoIf("Local/401@from-queue-eded,2", "0?exit|return") in new stack
    -- Executing [s@macro-exten-vm:11] Set("Local/401@from-queue-eded,2", "SV_DIALSTATUS=NOANSWER") in new stack
    -- Executing [s@macro-exten-vm:12] GosubIf("Local/401@from-queue-eded,2", "0?docfu|1") in new stack
    -- Executing [s@macro-exten-vm:13] GosubIf("Local/401@from-queue-eded,2", "0?docfb|1") in new stack
    -- Executing [s@macro-exten-vm:14] Set("Local/401@from-queue-eded,2", "DIALSTATUS=NOANSWER") in new stack
    -- Executing [s@macro-exten-vm:15] NoOp("Local/401@from-queue-eded,2", "Voicemail is 401") in new stack
    -- Executing [s@macro-exten-vm:16] GotoIf("Local/401@from-queue-eded,2", "0?s-NOANSWER|1") in new stack
    -- Executing [s@macro-exten-vm:17] NoOp("Local/401@from-queue-eded,2", "Sending to Voicemail box 401") in new stack
    -- Executing [s@macro-exten-vm:18] Macro("Local/401@from-queue-eded,2", "vm|401|NOANSWER|") in new stack
    -- Executing [s@macro-vm:1] Macro("Local/401@from-queue-eded,2", "user-callerid|SKIPTTL") in new stack
    -- Executing [s@macro-user-callerid:1] Set("Local/401@from-queue-eded,2", "AMPUSER=6157244200") in new stack
    -- Executing [s@macro-user-callerid:2] GotoIf("Local/401@from-queue-eded,2", "1?report") in new stack
    -- Goto (macro-user-callerid,s,9)
    -- Executing [s@macro-user-callerid:9] GotoIf("Local/401@from-queue-eded,2", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,18)
    -- Executing [s@macro-user-callerid:18] NoOp("Local/401@from-queue-eded,2", "Using CallerID "Private " <6157244200>") in new stack
    -- Executing [s@macro-vm:2] Set("Local/401@from-queue-eded,2", "VMGAIN=""") in new stack
    -- Executing [s@macro-vm:3] GotoIf("Local/401@from-queue-eded,2", "0?vmx|1") in new stack
    -- Executing [s@macro-vm:4] NoOp("Local/401@from-queue-eded,2", "CAME FROM: 700 - Blocking VM cause of key: ") in new stack
    -- Executing [s@macro-vm:5] Hangup("Local/401@from-queue-eded,2", "") in new stack
  == Spawn extension (macro-vm, s, 5) exited non-zero on 'Local/401@from-queue-eded,2' in macro 'vm'
  == Spawn extension (macro-exten-vm, s, 18) exited non-zero on 'Local/401@from-queue-eded,2' in macro 'exten-vm'
  == Spawn extension (from-internal, 401, 1) exited non-zero on 'Local/401@from-queue-eded,2'
    -- Executing [h@from-internal:1] Macro("Local/401@from-queue-eded,2", "hangupcall") in new stack
    -- Executing [s@macro-hangupcall:1] GotoIf("Local/401@from-queue-eded,2", "1?skiprg") in new stack
    -- Goto (macro-hangupcall,s,4)
    -- Executing [s@macro-hangupcall:4] GotoIf("Local/401@from-queue-eded,2", "1?skipblkvm") in new stack
    -- Goto (macro-hangupcall,s,7)
    -- Executing [s@macro-hangupcall:7] GotoIf("Local/401@from-queue-eded,2", "1?theend") in new stack
    -- Goto (macro-hangupcall,s,9)
    -- Executing [s@macro-hangupcall:9] Hangup("Local/401@from-queue-eded,2", "") in new stack
  == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'Local/401@from-queue-eded,2' in macro 'hangupcall'
  == Spawn extension (from-internal, h, 1) exited non-zero on 'Local/401@from-queue-eded,2'
    -- Nobody picked up in 15000 ms
    -- Executing [404@from-queue:1] Set("Local/404@from-queue-5118,2", "QAGENT=404") in new stack
    -- Executing [404@from-queue:2] Goto("Local/404@from-queue-5118,2", "700|1") in new stack
    -- Goto (from-queue,700,1)
    -- Executing [700@from-queue:1] Goto("Local/404@from-queue-5118,2", "from-internal|404|1") in new stack
    -- Goto (from-internal,404,1)
    -- Executing [404@from-internal:1] Macro("Local/404@from-queue-5118,2", "exten-vm|404|404") in new stack
    -- Executing [s@macro-exten-vm:1] Macro("Local/404@from-queue-5118,2", "user-callerid|") in new stack
    -- Executing [s@macro-user-callerid:1] Set("Local/404@from-queue-5118,2", "AMPUSER=6157244200") in new stack
    -- Executing [s@macro-user-callerid:2] GotoIf("Local/404@from-queue-5118,2", "1?report") in new stack
    -- Goto (macro-user-callerid,s,9)
    -- Executing [s@macro-user-callerid:9] GotoIf("Local/404@from-queue-5118,2", "0?continue") in new stack
    -- Executing [s@macro-user-callerid:10] Set("Local/404@from-queue-5118,2", "__TTL=63") in new stack
    -- Executing [s@macro-user-callerid:11] GotoIf("Local/404@from-queue-5118,2", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,18)
    -- Executing [s@macro-user-callerid:18] NoOp("Local/404@from-queue-5118,2", "Using CallerID "Private " <6157244200>") in new stack
    -- Executing [s@macro-exten-vm:2] Set("Local/404@from-queue-5118,2", "RingGroupMethod=none") in new stack
    -- Executing [s@macro-exten-vm:3] Set("Local/404@from-queue-5118,2", "VMBOX=404") in new stack
    -- Executing [s@macro-exten-vm:4] Set("Local/404@from-queue-5118,2", "__EXTTOCALL=404") in new stack
    -- Executing [s@macro-exten-vm:5] Set("Local/404@from-queue-5118,2", "CFUEXT=") in new stack
    -- Executing [s@macro-exten-vm:6] Set("Local/404@from-queue-5118,2", "CFBEXT=") in new stack
    -- Executing [s@macro-exten-vm:7] Set("Local/404@from-queue-5118,2", "RT=15") in new stack
    -- Executing [s@macro-exten-vm:8] Macro("Local/404@from-queue-5118,2", "record-enable|404|IN") in new stack
    -- Executing [s@macro-record-enable:1] GotoIf("Local/404@from-queue-5118,2", "1?check") in new stack
    -- Goto (macro-record-enable,s,4)
    -- Executing [s@macro-record-enable:4] ExecIf("Local/404@from-queue-5118,2", "0|MacroExit|") in new stack
    -- Executing [s@macro-record-enable:5] GotoIf("Local/404@from-queue-5118,2", "0?Group:OUT") in new stack
    -- Goto (macro-record-enable,s,15)
    -- Executing [s@macro-record-enable:15] GotoIf("Local/404@from-queue-5118,2", "1?IN") in new stack
    -- Goto (macro-record-enable,s,20)
    -- Executing [s@macro-record-enable:20] ExecIf("Local/404@from-queue-5118,2", "1|MacroExit|") in new stack
    -- Executing [s@macro-exten-vm:9] Macro("Local/404@from-queue-5118,2", "dial|15|trwWM(auto-blkvm)|404") in new stack
    -- Executing [s@macro-dial:1] GotoIf("Local/404@from-queue-5118,2", "1?dial") in new stack
    -- Goto (macro-dial,s,3)
    -- Executing [s@macro-dial:3] AGI("Local/404@from-queue-5118,2", "dialparties.agi") in new stack
    -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
  dialparties.agi: Starting New Dialparties.agi
  == Parsing '/etc/asterisk/manager.conf': Found
  == Parsing '/etc/asterisk/manager_additional.conf': Found
  == Parsing '/etc/asterisk/manager_custom.conf': Found
  == Manager 'admin' logged on from 127.0.0.1
  dialparties.agi: Caller ID name is 'Private' number is '6157244200'
  dialparties.agi: USE_CONFIRMATION:  'FALSE'
  dialparties.agi: RINGGROUP_INDEX:   ''
  dialparties.agi: Methodology of ring is  'none'
    --  dialparties.agi: Added extension 404 to extension map
    --  dialparties.agi: Extension 404 cf is disabled
    --  dialparties.agi: Extension 404 do not disturb is disabled
       >  dialparties.agi: extnum 404 has:  cw: 0; hascfb: 0 [] hascfu: 0 []
  dialparties.agi: ExtensionState: 0
  dialparties.agi: Extension 404 has ExtensionState: 0
    --  dialparties.agi: Checking CW and CFB status for extension 404
    --  dialparties.agi: dbset CALLTRACE/404 to 6157244200
    --  dialparties.agi: Filtered ARG3: 404
       >  dialparties.agi: NODEST: 700 blkvm enabled macro already in dialopts: trwWM(auto-blkvm)
       >  dialparties.agi: NODEST: 700 blkvm enabled macro already in dialopts: trwWM(auto-blkvm)
  == Manager 'admin' logged off from 127.0.0.1
    -- AGI Script dialparties.agi completed, returning 0
    -- Executing [s@macro-dial:7] Dial("Local/404@from-queue-5118,2", "SIP/404|15|trwWM(auto-blkvm)") in new stack
    -- Called 404
    -- Local/404@from-queue-5118,1 is ringing
    -- SIP/404-00000012 is ringing
    -- SIP/404-00000012 is ringing
    -- Nobody picked up in 15000 ms
  == Spawn extension (macro-dial, s, 7) exited non-zero on 'Local/404@from-queue-5118,2' in macro 'dial'
  == Spawn extension (macro-exten-vm, s, 9) exited non-zero on 'Local/404@from-queue-5118,2' in macro 'exten-vm'
  == Spawn extension (from-internal, 404, 1) exited non-zero on 'Local/404@from-queue-5118,2'
    -- Executing [h@macro-dial:1] Macro("Local/404@from-queue-5118,2", "hangupcall") in new stack
    -- Executing [s@macro-hangupcall:1] GotoIf("Local/404@from-queue-5118,2", "1?skiprg") in new stack
    -- Goto (macro-hangupcall,s,4)
    -- Executing [s@macro-hangupcall:4] GotoIf("Local/404@from-queue-5118,2", "1?skipblkvm") in new stack
    -- Goto (macro-hangupcall,s,7)
    -- Executing [s@macro-hangupcall:7] GotoIf("Local/404@from-queue-5118,2", "1?theend") in new stack
    -- Goto (macro-hangupcall,s,9)
    -- Executing [s@macro-hangupcall:9] Hangup("Local/404@from-queue-5118,2", "") in new stack
  == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'Local/404@from-queue-5118,2' in macro 'hangupcall'
  == Spawn extension (macro-dial, h, 1) exited non-zero on 'Local/404@from-queue-5118,2'
pbx*CLI> noanswer and other phone
No such command 'noanswer and other phone' (type 'help noanswer and' for other possible commands)
pbx*CLI> 
pbx*CLI> 
pbx*CLI> 
pbx*CLI> 
pbx*CLI> 
    -- Stopped music on hold on SIP/fpbx-1-afa853cf-0000000e
  == Spawn extension (ext-queues, 700, 11) exited non-zero on 'SIP/fpbx-1-afa853cf-0000000e'
pbx*CLI>