Inconsistent results with parking lot timeout

I’ve just installed FreePBX Distro on a client’s system and everything has gone swimmingly well with the exception of the timeout of parked calls. More likely than not, a call that times out does not ring back to the parking device (even though I have that option on) and does not ring through the alternate destination (set to a queue). Instead the parked call is dropped. Occasionally it functions as normal

FreePBX 12.0.47
Asterisk 11.16.0

For example this morning, here was a test call
Trunk -> Catch All Incoming Route -> Time Condition (negative) -> Time Condition (positive) -> Queue (1 static agent, multiple dynamic agents) -> Picked up by the static agent -> Parked -> Parked Call timed out and returned to parking device -> Pickup up by original parking device -> Reparked -> Parked Call timed out and result was a hangup.

A subsequent test call to that same queue and same static agent was dropped after the parked call timedout

I called again and this time a static agent from a subsequent queue picked up and repeated the scenario above… First park time out was successful and the second hung up.

I’d like to post the log but it’s too long for the forum and it won’t let me post a link to it.

Any thoughts on resolving this?

Let’s see if the forum will let me split the log in half… First half:

[2015-03-25 07:44:00] VERBOSE[28242][C-000019b2] pbx.c:   == Spawn extension (tc-maint, s, 6) exited non-zero on 'Local/s@tc-maint-00001a5c;2'
[2015-03-25 07:44:11] VERBOSE[2016][C-000019b3] netsock2.c:   == Using SIP RTP TOS bits 184
[2015-03-25 07:44:11] VERBOSE[2016][C-000019b3] netsock2.c:   == Using SIP RTP CoS mark 5
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [7777@from-trunk:1] NoOp("SIP/Mediatrix1204-00000351", "Catch-All DID Match - Found 7777 - You probably want a DID for this.") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [7777@from-trunk:2] Log("SIP/Mediatrix1204-00000351", "WARNING,Friendly Scanner from 192.168.11.3;branch=z9hG4bK04b646de2") in new stack
[2015-03-25 07:44:11] WARNING[28274][C-000019b3] Ext. 7777: Friendly Scanner from 192.168.11.3;branch=z9hG4bK04b646de2
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [7777@from-trunk:3] Set("SIP/Mediatrix1204-00000351", "__FROM_DID=7777") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [7777@from-trunk:4] Goto("SIP/Mediatrix1204-00000351", "ext-did,s,1") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Goto (ext-did,s,1)
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@ext-did:1] ExecIf("SIP/Mediatrix1204-00000351", "0?Set(__FROM_DID=s)") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@ext-did:2] Gosub("SIP/Mediatrix1204-00000351", "app-blacklist-check,s,1()") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@app-blacklist-check:1] GotoIf("SIP/Mediatrix1204-00000351", "0?blacklisted") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@app-blacklist-check:2] Set("SIP/Mediatrix1204-00000351", "CALLED_BLACKLIST=1") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@app-blacklist-check:3] Return("SIP/Mediatrix1204-00000351", "") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@ext-did:3] Set("SIP/Mediatrix1204-00000351", "CDR(did)=7777") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@ext-did:4] ExecIf("SIP/Mediatrix1204-00000351", "0 ?Set(CALLERID(name)=mycallerid)") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@ext-did:5] Set("SIP/Mediatrix1204-00000351", "CHANNEL(musicclass)=default") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@ext-did:6] Set("SIP/Mediatrix1204-00000351", "__MOHCLASS=default") in new stack
[2015-03-25 07:44:11] WARNING[28274][C-000019b3] func_channel.c: Unknown or unavailable item requested: 'reversecharge'
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@ext-did:7] GotoIf("SIP/Mediatrix1204-00000351", "0?macro-hangupcall") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@ext-did:8] Set("SIP/Mediatrix1204-00000351", "__CALLINGPRES_SV=allowed_not_screened") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@ext-did:9] Set("SIP/Mediatrix1204-00000351", "CALLERPRES()=allowed_not_screened") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@ext-did:10] Goto("SIP/Mediatrix1204-00000351", "timeconditions,2,1") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Goto (timeconditions,2,1)
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [2@timeconditions:1] Set("SIP/Mediatrix1204-00000351", "DB(TC/2/INUSESTATE)=INUSE") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [2@timeconditions:2] Set("SIP/Mediatrix1204-00000351", "DB(TC/2/NOT_INUSESTATE)=NOT_INUSE") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [2@timeconditions:3] GotoIfTime("SIP/Mediatrix1204-00000351", "07:30-16:30,*,25,may?truestate") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [2@timeconditions:4] GotoIf("SIP/Mediatrix1204-00000351", "0?truegoto") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [2@timeconditions:5] ExecIf("SIP/Mediatrix1204-00000351", "0?Set(DB(TC/2)=)") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [2@timeconditions:6] Set("SIP/Mediatrix1204-00000351", "DEVICE_STATE(Custom:TC2)=INUSE") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [2@timeconditions:7] ExecIf("SIP/Mediatrix1204-00000351", "0?Set(DEVICE_STATE(Custom:TCSTICKY)=INUSE)") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [2@timeconditions:8] GotoIf("SIP/Mediatrix1204-00000351", "1?timeconditions,1,1") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Goto (timeconditions,1,1)
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [1@timeconditions:1] Set("SIP/Mediatrix1204-00000351", "DB(TC/1/INUSESTATE)=INUSE") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [1@timeconditions:2] Set("SIP/Mediatrix1204-00000351", "DB(TC/1/NOT_INUSESTATE)=NOT_INUSE") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [1@timeconditions:3] GotoIfTime("SIP/Mediatrix1204-00000351", "07:30-16:30,mon-fri,*,*?truestate") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Goto (timeconditions,1,12)
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [1@timeconditions:12] GotoIf("SIP/Mediatrix1204-00000351", "0?falsegoto") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [1@timeconditions:13] ExecIf("SIP/Mediatrix1204-00000351", "0?Set(DB(TC/1)=)") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [1@timeconditions:14] Set("SIP/Mediatrix1204-00000351", "DEVICE_STATE(Custom:TC1)=NOT_INUSE") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [1@timeconditions:15] ExecIf("SIP/Mediatrix1204-00000351", "0?Set(DEVICE_STATE(Custom:TCSTICKY)=INUSE)") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [1@timeconditions:16] GotoIf("SIP/Mediatrix1204-00000351", "1?ext-queues,9001,1") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Goto (ext-queues,9001,1)
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:1] Macro("SIP/Mediatrix1204-00000351", "user-callerid,") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@macro-user-callerid:1] Set("SIP/Mediatrix1204-00000351", "TOUCH_MONITOR=1427287451.14404") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@macro-user-callerid:2] Set("SIP/Mediatrix1204-00000351", "AMPUSER=mycallerid") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@macro-user-callerid:3] GotoIf("SIP/Mediatrix1204-00000351", "0?report") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@macro-user-callerid:4] ExecIf("SIP/Mediatrix1204-00000351", "1?Set(REALCALLERIDNUM=mycallerid)") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@macro-user-callerid:5] Set("SIP/Mediatrix1204-00000351", "AMPUSER=") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@macro-user-callerid:6] GotoIf("SIP/Mediatrix1204-00000351", "0?limit") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@macro-user-callerid:7] Set("SIP/Mediatrix1204-00000351", "AMPUSERCIDNAME=") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@macro-user-callerid:8] GotoIf("SIP/Mediatrix1204-00000351", "1?report") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Goto (macro-user-callerid,s,16)
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@macro-user-callerid:16] GotoIf("SIP/Mediatrix1204-00000351", "0?continue") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@macro-user-callerid:17] ExecIf("SIP/Mediatrix1204-00000351", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@macro-user-callerid:18] Set("SIP/Mediatrix1204-00000351", "__TTL=64") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@macro-user-callerid:19] GotoIf("SIP/Mediatrix1204-00000351", "1?continue") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Goto (macro-user-callerid,s,30)
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@macro-user-callerid:30] Set("SIP/Mediatrix1204-00000351", "CALLERID(number)=mycallerid") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@macro-user-callerid:31] Set("SIP/Mediatrix1204-00000351", "CALLERID(name)=my CNAM") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@macro-user-callerid:32] Set("SIP/Mediatrix1204-00000351", "CDR(cnum)=mycallerid") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@macro-user-callerid:33] Set("SIP/Mediatrix1204-00000351", "CDR(cnam)=my CNAM") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@macro-user-callerid:34] Set("SIP/Mediatrix1204-00000351", "CHANNEL(language)=en") in new stack
[2015-03-25 07:44:11] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:2] Answer("SIP/Mediatrix1204-00000351", "") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:3] Macro("SIP/Mediatrix1204-00000351", "blkvm-set,reset") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@macro-blkvm-set:1] ExecIf("SIP/Mediatrix1204-00000351", "1?Set(__BLKVM_CHANNEL=SIP/Mediatrix1204-00000351)") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@macro-blkvm-set:2] Set("SIP/Mediatrix1204-00000351", "SHARED(BLKVM,SIP/Mediatrix1204-00000351)=TRUE") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@macro-blkvm-set:3] Set("SIP/Mediatrix1204-00000351", "GOSUB_RETVAL=TRUE") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@macro-blkvm-set:4] MacroExit("SIP/Mediatrix1204-00000351", "") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:4] ExecIf("SIP/Mediatrix1204-00000351", "1?Set(_DIAL_OPTIONS=TtrM(auto-blkvm))") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:5] Set("SIP/Mediatrix1204-00000351", "__NODEST=9001") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:6] Set("SIP/Mediatrix1204-00000351", "QCIDPP=") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:7] Set("SIP/Mediatrix1204-00000351", "VQ_CIDPP=") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:8] ExecIf("SIP/Mediatrix1204-00000351", "0?Macro(prepend-cid,)") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:9] Set("SIP/Mediatrix1204-00000351", "QAINFO=") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:10] Set("SIP/Mediatrix1204-00000351", "VQ_AINFO=") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:11] ExecIf("SIP/Mediatrix1204-00000351", "0?Set(__ALERT_INFO=)") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:12] Set("SIP/Mediatrix1204-00000351", "QJOINMSG=") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:13] Set("SIP/Mediatrix1204-00000351", "VQ_JOINMSG=") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:14] Set("SIP/Mediatrix1204-00000351", "QRINGOPTS=r") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:15] Set("SIP/Mediatrix1204-00000351", "QRETRY=") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:16] Set("SIP/Mediatrix1204-00000351", "VQ_RETRY=") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:17] Set("SIP/Mediatrix1204-00000351", "QOPTIONS=tr") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:18] Set("SIP/Mediatrix1204-00000351", "VQ_OPTIONS=") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:19] Set("SIP/Mediatrix1204-00000351", "QGOSUB=") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:20] Set("SIP/Mediatrix1204-00000351", "VQ_GOSUB=") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:21] Set("SIP/Mediatrix1204-00000351", "QAGI=") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:22] Set("SIP/Mediatrix1204-00000351", "VQ_AGI=") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:23] Set("SIP/Mediatrix1204-00000351", "QRULE=") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:24] Set("SIP/Mediatrix1204-00000351", "VQ_RULE=") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:25] Set("SIP/Mediatrix1204-00000351", "QPOSITION=") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:26] Set("SIP/Mediatrix1204-00000351", "VQ_POSITION=") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:27] Gosub("SIP/Mediatrix1204-00000351", "sub-record-check,s,1(q,9001,dontcare)") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@sub-record-check:1] GotoIf("SIP/Mediatrix1204-00000351", "0?initialized") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@sub-record-check:2] Set("SIP/Mediatrix1204-00000351", "__REC_STATUS=INITIALIZED") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@sub-record-check:3] Set("SIP/Mediatrix1204-00000351", "NOW=1427287452") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@sub-record-check:4] Set("SIP/Mediatrix1204-00000351", "__DAY=25") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@sub-record-check:5] Set("SIP/Mediatrix1204-00000351", "__MONTH=03") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@sub-record-check:6] Set("SIP/Mediatrix1204-00000351", "__YEAR=2015") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@sub-record-check:7] Set("SIP/Mediatrix1204-00000351", "__TIMESTR=20150325-074412") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@sub-record-check:8] Set("SIP/Mediatrix1204-00000351", "__FROMEXTEN=mycallerid") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@sub-record-check:9] Set("SIP/Mediatrix1204-00000351", "__MON_FMT=wav") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@sub-record-check:10] NoOp("SIP/Mediatrix1204-00000351", "Recordings initialized") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@sub-record-check:11] ExecIf("SIP/Mediatrix1204-00000351", "0?Set(ARG3=dontcare)") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@sub-record-check:12] Set("SIP/Mediatrix1204-00000351", "REC_POLICY_MODE_SAVE=") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@sub-record-check:13] ExecIf("SIP/Mediatrix1204-00000351", "0?Set(REC_STATUS=NO)") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@sub-record-check:14] GotoIf("SIP/Mediatrix1204-00000351", "1?checkaction") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Goto (sub-record-check,s,17)
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@sub-record-check:17] GotoIf("SIP/Mediatrix1204-00000351", "0?sub-record-check,q,1") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@sub-record-check:18] NoOp("SIP/Mediatrix1204-00000351", "Generic q Recording Check - mycallerid 9001") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@sub-record-check:19] Gosub("SIP/Mediatrix1204-00000351", "recordcheck,1(dontcare,q,9001)") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [recordcheck@sub-record-check:1] NoOp("SIP/Mediatrix1204-00000351", "Starting recording check against dontcare") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [recordcheck@sub-record-check:2] Goto("SIP/Mediatrix1204-00000351", "dontcare") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Goto (sub-record-check,recordcheck,3)
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [recordcheck@sub-record-check:3] Return("SIP/Mediatrix1204-00000351", "") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@sub-record-check:20] Return("SIP/Mediatrix1204-00000351", "") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:28] Set("SIP/Mediatrix1204-00000351", "__CWIGNORE=TRUE") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:29] ExecIf("SIP/Mediatrix1204-00000351", "0?Playback(, )") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:30] QueueLog("SIP/Mediatrix1204-00000351", "9001,1427287451.14404,NONE,DID,7777") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:31] Set("SIP/Mediatrix1204-00000351", "QAANNOUNCE=") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:32] Set("SIP/Mediatrix1204-00000351", "VQ_AANNOUNCE=") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:33] Set("SIP/Mediatrix1204-00000351", "QMOH=") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:34] Set("SIP/Mediatrix1204-00000351", "VQ_MOH=") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:35] ExecIf("SIP/Mediatrix1204-00000351", "0?Set(__MOHCLASS=)") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:36] ExecIf("SIP/Mediatrix1204-00000351", "1?Set(CHANNEL(musicclass)=default)") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:37] Set("SIP/Mediatrix1204-00000351", "QMAXWAIT=10") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:38] Set("SIP/Mediatrix1204-00000351", "VQ_MAXWAIT=") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:39] Set("SIP/Mediatrix1204-00000351", "QUEUENUM=9001") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:40] Set("SIP/Mediatrix1204-00000351", "QUEUEJOINTIME=1427287452") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [9001@ext-queues:41] Queue("SIP/Mediatrix1204-00000351", "9001,tr,,,10,,,,,") in new stack
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] app_queue.c:     -- Called Local/103@from-queue/n
[2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] app_queue.c:     -- LazyMembers debugging - Numbusies: 0, Nummems: 1
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [103@from-queue:1] Set("Local/103@from-queue-00001a5d;2", "QAGENT=103") in new stack
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [103@from-queue:2] Goto("Local/103@from-queue-00001a5d;2", "9001,1") in new stack
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Goto (from-queue,9001,1)
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [9001@from-queue:1] Goto("Local/103@from-queue-00001a5d;2", "from-internal,103,1") in new stack
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Goto (from-internal,103,1)
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [103@from-internal:1] GotoIf("Local/103@from-queue-00001a5d;2", "1?ext-local,103,1") in new stack
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Goto (ext-local,103,1)
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [103@ext-local:1] Set("Local/103@from-queue-00001a5d;2", "__RINGTIMER=15") in new stack
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [103@ext-local:2] Macro("Local/103@from-queue-00001a5d;2", "exten-vm,103,103,0,0,0") in new stack
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-exten-vm:1] Macro("Local/103@from-queue-00001a5d;2", "user-callerid,") in new stack
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-user-callerid:1] Set("Local/103@from-queue-00001a5d;2", "TOUCH_MONITOR=1427287452.14406") in new stack
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-user-callerid:2] Set("Local/103@from-queue-00001a5d;2", "AMPUSER=mycallerid") in new stack
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-user-callerid:3] GotoIf("Local/103@from-queue-00001a5d;2", "1?report") in new stack
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Goto (macro-user-callerid,s,16)
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-user-callerid:16] GotoIf("Local/103@from-queue-00001a5d;2", "0?continue") in new stack
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-user-callerid:17] ExecIf("Local/103@from-queue-00001a5d;2", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-user-callerid:18] Set("Local/103@from-queue-00001a5d;2", "__TTL=63") in new stack
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-user-callerid:19] GotoIf("Local/103@from-queue-00001a5d;2", "1?continue") in new stack
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Goto (macro-user-callerid,s,30)
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-user-callerid:30] Set("Local/103@from-queue-00001a5d;2", "CALLERID(number)=mycallerid") in new stack
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-user-callerid:31] Set("Local/103@from-queue-00001a5d;2", "CALLERID(name)=my CNAM") in new stack
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-user-callerid:32] Set("Local/103@from-queue-00001a5d;2", "CDR(cnum)=mycallerid") in new stack
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-user-callerid:33] Set("Local/103@from-queue-00001a5d;2", "CDR(cnam)=my CNAM") in new stack
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-user-callerid:34] Set("Local/103@from-queue-00001a5d;2", "CHANNEL(language)=en") in new stack
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-exten-vm:2] Set("Local/103@from-queue-00001a5d;2", "RingGroupMethod=none") in new stack
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-exten-vm:3] Set("Local/103@from-queue-00001a5d;2", "__EXTTOCALL=103") in new stack
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-exten-vm:4] Set("Local/103@from-queue-00001a5d;2", "__PICKUPMARK=103") in new stack
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-exten-vm:5] Set("Local/103@from-queue-00001a5d;2", "RT=15") in new stack
[2015-03-25 07:44:12] WARNING[28275][C-000019b3] chan_sip.c: This function can only be used on SIP channels.
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-exten-vm:6] ExecIf("Local/103@from-queue-00001a5d;2", "0?Macro(vm,103,DIRECTDIAL,)") in new stack
[2015-03-25 07:44:12] WARNING[28275][C-000019b3] chan_sip.c: This function can only be used on SIP channels.
[2015-03-25 07:44:12] WARNING[28275][C-000019b3] chan_sip.c: This function can only be used on SIP channels.
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-exten-vm:7] ExecIf("Local/103@from-queue-00001a5d;2", "0?MacroExit()") in new stack
[2015-03-25 07:44:12] WARNING[28275][C-000019b3] chan_sip.c: This function can only be used on SIP channels.
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-exten-vm:8] Gosub("Local/103@from-queue-00001a5d;2", "sub-record-check,s,1(exten,103,dontcare)") in new stack
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@sub-record-check:1] GotoIf("Local/103@from-queue-00001a5d;2", "10?initialized") in new stack
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Goto (sub-record-check,s,10)
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@sub-record-check:10] NoOp("Local/103@from-queue-00001a5d;2", "Recordings initialized") in new stack
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@sub-record-check:11] ExecIf("Local/103@from-queue-00001a5d;2", "0?Set(ARG3=dontcare)") in new stack
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@sub-record-check:12] Set("Local/103@from-queue-00001a5d;2", "REC_POLICY_MODE_SAVE=") in new stack
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@sub-record-check:13] ExecIf("Local/103@from-queue-00001a5d;2", "0?Set(REC_STATUS=NO)") in new stack
[2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@sub-record-check:14] GotoIf("Local/103@from-queue-00001a5d;2", "5?checkaction") in new stack

Second half of log

   [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Goto (sub-record-check,s,17)
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@sub-record-check:17] GotoIf("Local/103@from-queue-00001a5d;2", "1?sub-record-check,exten,1") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Goto (sub-record-check,exten,1)
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [exten@sub-record-check:1] NoOp("Local/103@from-queue-00001a5d;2", "Exten Recording Check between mycallerid and 103") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [exten@sub-record-check:2] Set("Local/103@from-queue-00001a5d;2", "CALLTYPE=external") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [exten@sub-record-check:3] ExecIf("Local/103@from-queue-00001a5d;2", "0?Set(CALLTYPE=)") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [exten@sub-record-check:4] Set("Local/103@from-queue-00001a5d;2", "CALLEE=dontcare") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [exten@sub-record-check:5] ExecIf("Local/103@from-queue-00001a5d;2", "0?Set(CALLEE=dontcare)") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [exten@sub-record-check:6] GotoIf("Local/103@from-queue-00001a5d;2", "1?callee") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Goto (sub-record-check,exten,11)
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [exten@sub-record-check:11] Gosub("Local/103@from-queue-00001a5d;2", "recordcheck,1(dontcare,external,103)") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [recordcheck@sub-record-check:1] NoOp("Local/103@from-queue-00001a5d;2", "Starting recording check against dontcare") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [recordcheck@sub-record-check:2] Goto("Local/103@from-queue-00001a5d;2", "dontcare") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Goto (sub-record-check,recordcheck,3)
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [recordcheck@sub-record-check:3] Return("Local/103@from-queue-00001a5d;2", "") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [exten@sub-record-check:12] Return("Local/103@from-queue-00001a5d;2", "") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-exten-vm:9] GotoIf("Local/103@from-queue-00001a5d;2", "4?macrodial") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Goto (macro-exten-vm,s,15)
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-exten-vm:15] GosubIf("Local/103@from-queue-00001a5d;2", "0?clrheader,1()") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-exten-vm:16] Macro("Local/103@from-queue-00001a5d;2", "dial-one,15,TtrM(auto-blkvm),103") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-dial-one:1] Set("Local/103@from-queue-00001a5d;2", "DEXTEN=103") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-dial-one:2] Set("Local/103@from-queue-00001a5d;2", "DIALSTATUS_CW=") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-dial-one:3] GosubIf("Local/103@from-queue-00001a5d;2", "0?screen,1()") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-dial-one:4] GosubIf("Local/103@from-queue-00001a5d;2", "0?cf,1()") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-dial-one:5] GotoIf("Local/103@from-queue-00001a5d;2", "1?skip1") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Goto (macro-dial-one,s,8)
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-dial-one:8] GotoIf("Local/103@from-queue-00001a5d;2", "0?nodial") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-dial-one:9] GotoIf("Local/103@from-queue-00001a5d;2", "0?continue") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-dial-one:10] Set("Local/103@from-queue-00001a5d;2", "EXTHASCW=") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-dial-one:11] GotoIf("Local/103@from-queue-00001a5d;2", "1?next1:cwinusebusy") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Goto (macro-dial-one,s,12)
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-dial-one:12] GotoIf("Local/103@from-queue-00001a5d;2", "0?docfu:skip3") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Goto (macro-dial-one,s,16)
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-dial-one:16] GotoIf("Local/103@from-queue-00001a5d;2", "1?next2:continue") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Goto (macro-dial-one,s,17)
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-dial-one:17] GotoIf("Local/103@from-queue-00001a5d;2", "1?continue") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Goto (macro-dial-one,s,25)
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-dial-one:25] GotoIf("Local/103@from-queue-00001a5d;2", "0?nodial") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-dial-one:26] GosubIf("Local/103@from-queue-00001a5d;2", "1?dstring,1():dlocal,1()") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [dstring@macro-dial-one:1] Set("Local/103@from-queue-00001a5d;2", "DSTRING=") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [dstring@macro-dial-one:2] Set("Local/103@from-queue-00001a5d;2", "DEVICES=103") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [dstring@macro-dial-one:3] ExecIf("Local/103@from-queue-00001a5d;2", "0?Return()") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [dstring@macro-dial-one:4] ExecIf("Local/103@from-queue-00001a5d;2", "0?Set(DEVICES=03)") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [dstring@macro-dial-one:5] Set("Local/103@from-queue-00001a5d;2", "LOOPCNT=1") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [dstring@macro-dial-one:6] Set("Local/103@from-queue-00001a5d;2", "ITER=1") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [dstring@macro-dial-one:7] Set("Local/103@from-queue-00001a5d;2", "THISDIAL=SIP/103") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [dstring@macro-dial-one:8] GosubIf("Local/103@from-queue-00001a5d;2", "1?zap2dahdi,1()") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:1] ExecIf("Local/103@from-queue-00001a5d;2", "0?Return()") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:2] Set("Local/103@from-queue-00001a5d;2", "NEWDIAL=") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:3] Set("Local/103@from-queue-00001a5d;2", "LOOPCNT2=1") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:4] Set("Local/103@from-queue-00001a5d;2", "ITER2=1") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:5] Set("Local/103@from-queue-00001a5d;2", "THISPART2=SIP/103") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:6] ExecIf("Local/103@from-queue-00001a5d;2", "0?Set(THISPART2=DAHDI/103)") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:7] Set("Local/103@from-queue-00001a5d;2", "NEWDIAL=SIP/103&") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:8] Set("Local/103@from-queue-00001a5d;2", "ITER2=2") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:9] GotoIf("Local/103@from-queue-00001a5d;2", "0?begin2") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:10] Set("Local/103@from-queue-00001a5d;2", "THISDIAL=SIP/103") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [zap2dahdi@macro-dial-one:11] Return("Local/103@from-queue-00001a5d;2", "") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [dstring@macro-dial-one:9] GotoIf("Local/103@from-queue-00001a5d;2", "1?doset") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Goto (macro-dial-one,dstring,12)
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [dstring@macro-dial-one:12] Set("Local/103@from-queue-00001a5d;2", "DSTRING=SIP/103&") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [dstring@macro-dial-one:13] Set("Local/103@from-queue-00001a5d;2", "ITER=2") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [dstring@macro-dial-one:14] GotoIf("Local/103@from-queue-00001a5d;2", "0?begin") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [dstring@macro-dial-one:15] Set("Local/103@from-queue-00001a5d;2", "DSTRING=SIP/103") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [dstring@macro-dial-one:16] Return("Local/103@from-queue-00001a5d;2", "") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-dial-one:27] GotoIf("Local/103@from-queue-00001a5d;2", "0?nodial") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-dial-one:28] GotoIf("Local/103@from-queue-00001a5d;2", "0?skiptrace") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-dial-one:29] GosubIf("Local/103@from-queue-00001a5d;2", "1?ctset,1():ctclear,1()") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [ctset@macro-dial-one:1] Set("Local/103@from-queue-00001a5d;2", "DB(CALLTRACE/103)=mycallerid") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [ctset@macro-dial-one:2] Return("Local/103@from-queue-00001a5d;2", "") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-dial-one:30] Set("Local/103@from-queue-00001a5d;2", "D_OPTIONS=TtrM(auto-blkvm)") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-dial-one:31] ExecIf("Local/103@from-queue-00001a5d;2", "0?SIPAddHeader(Alert-Info: )") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-dial-one:32] ExecIf("Local/103@from-queue-00001a5d;2", "0?SIPAddHeader()") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-dial-one:33] ExecIf("Local/103@from-queue-00001a5d;2", "1?Set(CHANNEL(musicclass)=default)") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-dial-one:34] GosubIf("Local/103@from-queue-00001a5d;2", "0?qwait,1()") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-dial-one:35] Set("Local/103@from-queue-00001a5d;2", "__CWIGNORE=TRUE") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-dial-one:36] Set("Local/103@from-queue-00001a5d;2", "__KEEPCID=TRUE") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-dial-one:37] GotoIf("Local/103@from-queue-00001a5d;2", "0?usegoto,1") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-dial-one:38] GotoIf("Local/103@from-queue-00001a5d;2", "1?godial") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Goto (macro-dial-one,s,43)
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-dial-one:43] Macro("Local/103@from-queue-00001a5d;2", "dialout-one-predial-hook,") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-dialout-one-predial-hook:1] MacroExit("Local/103@from-queue-00001a5d;2", "") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-dial-one:44] Dial("Local/103@from-queue-00001a5d;2", "SIP/103,15,TtrM(auto-blkvm)") in new stack
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] netsock2.c:   == Using SIP RTP TOS bits 184
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] netsock2.c:   == Using SIP RTP CoS mark 5
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] app_dial.c:     -- Called SIP/103
    [2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] app_queue.c:     -- Local/103@from-queue-00001a5d;1 is ringing
    [2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] app_queue.c:     -- Local/103@from-queue-00001a5d;1 connected line has changed. Saving it until answer for SIP/Mediatrix1204-00000351
    [2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] app_queue.c:     -- Local/103@from-queue-00001a5d;1 connected line has changed. Saving it until answer for SIP/Mediatrix1204-00000351
    [2015-03-25 07:44:12] VERBOSE[28275][C-000019b3] app_dial.c:     -- SIP/103-00000352 is ringing
    [2015-03-25 07:44:12] VERBOSE[28274][C-000019b3] app_queue.c:     -- Local/103@from-queue-00001a5d;1 is ringing
    [2015-03-25 07:44:21] VERBOSE[28275][C-000019b3] app_dial.c:     -- SIP/103-00000352 answered Local/103@from-queue-00001a5d;2
    [2015-03-25 07:44:21] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-auto-blkvm:1] Set("SIP/103-00000352", "__MACRO_RESULT=") in new stack
    [2015-03-25 07:44:21] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-auto-blkvm:2] Set("SIP/103-00000352", "CFIGNORE=") in new stack
    [2015-03-25 07:44:21] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-auto-blkvm:3] Set("SIP/103-00000352", "MASTER_CHANNEL(CFIGNORE)=") in new stack
    [2015-03-25 07:44:21] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-auto-blkvm:4] Set("SIP/103-00000352", "FORWARD_CONTEXT=from-internal") in new stack
    [2015-03-25 07:44:21] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-auto-blkvm:5] Set("SIP/103-00000352", "MASTER_CHANNEL(FORWARD_CONTEXT)=from-internal") in new stack
    [2015-03-25 07:44:21] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-auto-blkvm:6] Macro("SIP/103-00000352", "blkvm-clr,") in new stack
    [2015-03-25 07:44:21] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-blkvm-clr:1] Set("SIP/103-00000352", "SHARED(BLKVM,SIP/Mediatrix1204-00000351)=") in new stack
    [2015-03-25 07:44:21] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-blkvm-clr:2] Set("SIP/103-00000352", "GOSUB_RETVAL=") in new stack
    [2015-03-25 07:44:21] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-blkvm-clr:3] MacroExit("SIP/103-00000352", "") in new stack
    [2015-03-25 07:44:21] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-auto-blkvm:7] ExecIf("SIP/103-00000352", "0?Set(MASTER_CHANNEL(CONNECTEDLINE(num))=103)") in new stack
    [2015-03-25 07:44:21] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-auto-blkvm:8] ExecIf("SIP/103-00000352", "0?Set(MASTER_CHANNEL(CONNECTEDLINE(name))=Donna Coppola)") in new stack
    [2015-03-25 07:44:21] VERBOSE[28274][C-000019b3] app_queue.c:     -- Local/103@from-queue-00001a5d;1 connected line has changed. Saving it until answer for SIP/Mediatrix1204-00000351
    [2015-03-25 07:44:21] VERBOSE[28274][C-000019b3] app_queue.c:     -- Local/103@from-queue-00001a5d;1 answered SIP/Mediatrix1204-00000351
    [2015-03-25 07:46:04] VERBOSE[28275][C-000019b3] res_musiconhold.c:     -- Started music on hold, class 'default', on Local/103@from-queue-00001a5d;2
    [2015-03-25 07:46:04] VERBOSE[2016][C-000019b7] netsock2.c:   == Using SIP RTP TOS bits 184
    [2015-03-25 07:46:04] VERBOSE[2016][C-000019b7] netsock2.c:   == Using SIP RTP CoS mark 5
    [2015-03-25 07:46:04] VERBOSE[28352][C-000019b7] pbx.c:     -- Executing [70@from-internal:1] Park("SIP/103-00000353", "") in new stack
    [2015-03-25 07:46:06] VERBOSE[28352][C-000019b7] features.c:   == Parked SIP/103-00000353 on 71 (lot default). Will timeout back to extension [from-internal] s, 1 in 120 seconds
    [2015-03-25 07:46:06] VERBOSE[28352][C-000019b7] pbx.c:     -- Added extension '71' priority 1 to parkedcalls
    [2015-03-25 07:46:06] VERBOSE[28352][C-000019b7] file.c:     -- <SIP/103-00000353> Playing 'digits/7.ulaw' (language 'en')
    [2015-03-25 07:46:07] VERBOSE[28352][C-000019b7] file.c:     -- <SIP/103-00000353> Playing 'digits/1.ulaw' (language 'en')
    [2015-03-25 07:46:07] VERBOSE[2016][C-000019b3] res_musiconhold.c:     -- Stopped music on hold on Local/103@from-queue-00001a5d;2
    [2015-03-25 07:46:07] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [h@macro-dial-one:1] Macro("SIP/103-00000353<ZOMBIE>", "hangupcall,") in new stack
    [2015-03-25 07:46:07] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-hangupcall:1] ExecIf("SIP/103-00000353<ZOMBIE>", "0?Set(CDR(recordingfile)=.wav)") in new stack
    [2015-03-25 07:46:07] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-hangupcall:2] GotoIf("SIP/103-00000353<ZOMBIE>", "1?theend") in new stack
    [2015-03-25 07:46:07] VERBOSE[28275][C-000019b3] pbx.c:     -- Goto (macro-hangupcall,s,4)
    [2015-03-25 07:46:07] VERBOSE[28352][C-000019b7] res_musiconhold.c:     -- Started music on hold, class 'default', on Local/103@from-queue-00001a5d;2
    [2015-03-25 07:46:07] VERBOSE[28275][C-000019b3] pbx.c:     -- Executing [s@macro-hangupcall:4] Hangup("SIP/103-00000353<ZOMBIE>", "") in new stack
    [2015-03-25 07:46:07] VERBOSE[28352][C-000019b7] pbx.c:   == Spawn extension (from-internal, s, 1) exited non-zero on 'Parked/SIP/103-00000353<ZOMBIE>'
    [2015-03-25 07:46:07] VERBOSE[28352][C-000019b7] pbx.c:     -- Executing [h@from-internal:1] Hangup("Parked/SIP/103-00000353<ZOMBIE>", "") in new stack
    [2015-03-25 07:46:07] VERBOSE[28275][C-000019b3] app_macro.c:   == Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'SIP/103-00000353<ZOMBIE>' in macro 'hangupcall'
    [2015-03-25 07:46:07] VERBOSE[28352][C-000019b7] pbx.c:   == Spawn extension (from-internal, h, 1) exited non-zero on 'Parked/SIP/103-00000353<ZOMBIE>'
    [2015-03-25 07:46:07] VERBOSE[28275][C-000019b3] pbx.c:   == Spawn extension (macro-dial-one, h, 1) exited non-zero on 'SIP/103-00000353<ZOMBIE>'
    [2015-03-25 07:46:07] VERBOSE[28275][C-000019b3] app_macro.c:   == Spawn extension (macro-dial-one, s, 44) exited non-zero on 'SIP/103-00000353<ZOMBIE>' in macro 'dial-one'
    [2015-03-25 07:46:07] VERBOSE[28275][C-000019b3] app_macro.c:   == Spawn extension (macro-exten-vm, s, 16) exited non-zero on 'SIP/103-00000353<ZOMBIE>' in macro 'exten-vm'
    [2015-03-25 07:46:07] VERBOSE[28275][C-000019b3] pbx.c:   == Spawn extension (ext-local, 103, 2) exited non-zero on 'SIP/103-00000353<ZOMBIE>'
    [2015-03-25 07:48:06] VERBOSE[2008] res_musiconhold.c:     -- Stopped music on hold on Local/103@from-queue-00001a5d;2
    [2015-03-25 07:48:06] VERBOSE[2008] pbx.c:     -- Added extension 'SIP_103' priority 1 to park-dial
    [2015-03-25 07:48:06] VERBOSE[2008] features.c:   == Timeout for Local/103@from-queue-00001a5d;2 parked on 71 (default). Returning to parkedcallstimeout,SIP_103,1
    [2015-03-25 07:48:06] VERBOSE[28459][C-000019ba] pbx.c:     -- Executing [SIP_103@parkedcallstimeout:1] Set("Local/103@from-queue-00001a5d;2", "PARKCALLBACK=SIP/103") in new stack
    [2015-03-25 07:48:06] VERBOSE[28459][C-000019ba] pbx.c:     -- Executing [SIP_103@parkedcallstimeout:2] GotoIf("Local/103@from-queue-00001a5d;2", "1?next") in new stack
    [2015-03-25 07:48:06] VERBOSE[28459][C-000019ba] pbx.c:     -- Goto (parkedcallstimeout,SIP_103,5)
    [2015-03-25 07:48:06] VERBOSE[28459][C-000019ba] pbx.c:     -- Executing [SIP_103@parkedcallstimeout:5] Goto("Local/103@from-queue-00001a5d;2", "park-return-routing,71,1") in new stack
    [2015-03-25 07:48:06] VERBOSE[28459][C-000019ba] pbx.c:     -- Goto (park-return-routing,71,1)
    [2015-03-25 07:48:06] VERBOSE[28459][C-000019ba] pbx.c:     -- Executing [71@park-return-routing:1] Goto("Local/103@from-queue-00001a5d;2", "70,1") in new stack
    [2015-03-25 07:48:06] VERBOSE[28459][C-000019ba] pbx.c:     -- Goto (park-return-routing,70,1)
    [2015-03-25 07:48:06] VERBOSE[28459][C-000019ba] pbx.c:     -- Executing [70@park-return-routing:1] Set("Local/103@from-queue-00001a5d;2", "PLOT=70") in new stack
    [2015-03-25 07:48:06] VERBOSE[28459][C-000019ba] pbx.c:     -- Executing [70@park-return-routing:2] Dial("Local/103@from-queue-00001a5d;2", "SIP/103,15,tr") in new stack
    [2015-03-25 07:48:06] VERBOSE[28459][C-000019ba] netsock2.c:   == Using SIP RTP TOS bits 184
    [2015-03-25 07:48:06] VERBOSE[28459][C-000019ba] netsock2.c:   == Using SIP RTP CoS mark 5
    [2015-03-25 07:48:06] VERBOSE[28459][C-000019ba] app_dial.c:     -- Called SIP/103
    [2015-03-25 07:48:06] VERBOSE[28459][C-000019ba] app_dial.c:     -- SIP/103-00000354 is ringing
    [2015-03-25 07:48:11] VERBOSE[28459][C-000019ba] app_dial.c:     -- SIP/103-00000354 answered Local/103@from-queue-00001a5d;2
    [2015-03-25 07:50:39] VERBOSE[28459][C-000019ba] res_musiconhold.c:     -- Started music on hold, class 'default', on Local/103@from-queue-00001a5d;2
    [2015-03-25 07:50:40] VERBOSE[2016][C-000019bd] netsock2.c:   == Using SIP RTP TOS bits 184
    [2015-03-25 07:50:40] VERBOSE[2016][C-000019bd] netsock2.c:   == Using SIP RTP CoS mark 5
    [2015-03-25 07:50:40] VERBOSE[28537][C-000019bd] pbx.c:     -- Executing [70@from-internal:1] Park("SIP/103-00000355", "") in new stack
    [2015-03-25 07:50:40] VERBOSE[2016][C-000019ba] res_musiconhold.c:     -- Stopped music on hold on Local/103@from-queue-00001a5d;2
    [2015-03-25 07:50:40] VERBOSE[28459][C-000019ba] pbx.c:   == Spawn extension (park-return-routing, 70, 2) exited non-zero on 'SIP/103-00000355<ZOMBIE>'
    [2015-03-25 07:50:41] VERBOSE[28537][C-000019bd] features.c:   == Parked Local/103@from-queue-00001a5d;2 on 71 (lot default). Will timeout back to extension [from-internal] s, 1 in 120 seconds
    [2015-03-25 07:50:41] VERBOSE[28537][C-000019bd] pbx.c:     -- Added extension '71' priority 1 to parkedcalls
    [2015-03-25 07:50:41] VERBOSE[28537][C-000019bd] res_musiconhold.c:     -- Started music on hold, class 'default', on Local/103@from-queue-00001a5d;2
    [2015-03-25 07:50:41] VERBOSE[28537][C-000019bd] pbx.c:   == Spawn extension (from-internal, s, 1) exited non-zero on 'Parked/Local/103@from-queue-00001a5d;2<ZOMBIE>'
    [2015-03-25 07:50:41] VERBOSE[28537][C-000019bd] pbx.c:     -- Executing [h@from-internal:1] Hangup("Parked/Local/103@from-queue-00001a5d;2<ZOMBIE>", "") in new stack
    [2015-03-25 07:50:41] VERBOSE[28537][C-000019bd] pbx.c:   == Spawn extension (from-internal, h, 1) exited non-zero on 'Parked/Local/103@from-queue-00001a5d;2<ZOMBIE>'
    [2015-03-25 07:52:41] VERBOSE[2008] res_musiconhold.c:     -- Stopped music on hold on Local/103@from-queue-00001a5d;2
    [2015-03-25 07:52:41] VERBOSE[2008] features.c:   == Timeout for Local/103@from-queue-00001a5d;2 parked on 71 (default). Returning to from-internal,s,1
    [2015-03-25 07:52:41] VERBOSE[28615][C-000019c1] pbx.c:     -- Executing [s@from-internal:1] Macro("Local/103@from-queue-00001a5d;2", "hangupcall") in new stack
    [2015-03-25 07:52:41] VERBOSE[28615][C-000019c1] pbx.c:     -- Executing [s@macro-hangupcall:1] ExecIf("Local/103@from-queue-00001a5d;2", "0?Set(CDR(recordingfile)=.wav)") in new stack
    [2015-03-25 07:52:41] VERBOSE[28615][C-000019c1] pbx.c:     -- Executing [s@macro-hangupcall:2] GotoIf("Local/103@from-queue-00001a5d;2", "1?theend") in new stack
    [2015-03-25 07:52:41] VERBOSE[28615][C-000019c1] pbx.c:     -- Goto (macro-hangupcall,s,4)
    [2015-03-25 07:52:41] VERBOSE[28615][C-000019c1] pbx.c:     -- Executing [s@macro-hangupcall:4] Hangup("Local/103@from-queue-00001a5d;2", "") in new stack
    [2015-03-25 07:52:41] VERBOSE[28615][C-000019c1] app_macro.c:   == Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'Local/103@from-queue-00001a5d;2' in macro 'hangupcall'
    [2015-03-25 07:52:41] VERBOSE[28615][C-000019c1] pbx.c:   == Spawn extension (from-internal, s, 1) exited non-zero on 'Local/103@from-queue-00001a5d;2'
    [2015-03-25 07:52:41] VERBOSE[28615][C-000019c1] pbx.c:     -- Executing [h@from-internal:1] Hangup("Local/103@from-queue-00001a5d;2", "") in new stack
    [2015-03-25 07:52:41] VERBOSE[28615][C-000019c1] pbx.c:   == Spawn extension (from-internal, h, 1) exited non-zero on 'Local/103@from-queue-00001a5d;2'
    [2015-03-25 07:52:41] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [h@ext-queues:1] Macro("SIP/Mediatrix1204-00000351", "hangupcall,") in new stack
    [2015-03-25 07:52:41] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@macro-hangupcall:1] ExecIf("SIP/Mediatrix1204-00000351", "0?Set(CDR(recordingfile)=.wav)") in new stack
    [2015-03-25 07:52:41] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@macro-hangupcall:2] GotoIf("SIP/Mediatrix1204-00000351", "1?theend") in new stack
    [2015-03-25 07:52:41] VERBOSE[28274][C-000019b3] pbx.c:     -- Goto (macro-hangupcall,s,4)
    [2015-03-25 07:52:41] VERBOSE[28274][C-000019b3] pbx.c:     -- Executing [s@macro-hangupcall:4] Hangup("SIP/Mediatrix1204-00000351", "") in new stack
    [2015-03-25 07:52:41] VERBOSE[28274][C-000019b3] app_macro.c:   == Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'SIP/Mediatrix1204-00000351' in macro 'hangupcall'
    [2015-03-25 07:52:41] VERBOSE[28274][C-000019b3] pbx.c:   == Spawn extension (ext-queues, h, 1) exited non-zero on 'SIP/Mediatrix1204-00000351'
    [2015-03-25 07:52:41] VERBOSE[28274][C-000019b3] pbx.c:   == Spawn extension (ext-queues, 9001, 41) exited non-zero on 'SIP/Mediatrix1204-00000351'

What version of the parking lot module are you using?

I’m using 12.0.9 of the Parking Lot module.

You have a ton of log there. It’s really hard to follow and from what you’ve posted I see it returning to SIP/103 correctly. No where do I see a drop or hangup (which is usually do to incorrect context)

Also half way through your call turns into a < ZOMBIE >. Zombie calls are not a good thing. It’s basically a call where as the caller already hungup and now Asterisk is just parsing the channel without a caller. Your whole issue probably stems from these Zombies, not from Parking.

I suppose the key elements of the log above are in the first instance

    [2015-03-25 07:48:06] VERBOSE[2008] features.c:   == Timeout for Local/103@from-queue-00001a5d;2 parked on 71 (default). Returning to parkedcallstimeout,SIP_103,1

whereas in the second instance

    [2015-03-25 07:52:41] VERBOSE[2008] features.c:   == Timeout for Local/103@from-queue-00001a5d;2 parked on 71 (default). Returning to from-internal,s,1

I’m not sure where the ZOMBIEs are coming from… no one hung up except the parking device after the lot number was announced.

The log you posted above is 100% correct. The first one returns to SIP/103. The second one returns to from-internal. I see nothing wrong there. If there was something wrong it would say the context is invalid on the next line.

Also this looks like 103 is sending itself into a parking lot and then attempting to be sent back to itself. That won’t work for obvious reasons…

The problem is that your call is a zombie well before entering the Parking Lot.

In each case the call is transferred to the parking lot and music on hold is played. The hangup doesn’t occur until after the second park times out. Why would these calls be zombies if no one hangs up?

^ Is all automated on the side of Asterisk. Nothing in FreePBX can control that. The parking lot application is telling itself that “Will timeout back to extension [from-internal] s, 1 in 120 seconds”. Again, FreePBX can’t control that (Parking is largely an internal application in Asterisk using no dialplan).

Also note that at this point it’s a ZOMBIE, The channel is dead here.

I suggest you upgrade asterisk to 13 and see if you still have issues. Parking was largely re-written in 12. Almost from the ground up.

It’s very interesting that if you look at the first call, it too says it will return to [from-internal],s, 1 but returns correctly to [parkedcallstimeout]

Please upgrade to Asterisk 13 and see if this is still an issue. As I said previously. This was largely rewritten in 12 because of random issues in Parking and is significantly better in 12+

Yes that happened because your PBX did this: “[2015-03-25 07:48:06] VERBOSE[2008] pbx.c: – Added extension ‘SIP_103’ priority 1 to park-dial”

Again, not anything FreePBX can control, or is controlling. This is Asterisk automating the call from pbx.c

Note: At this point the call is a Zombie.

Ok… Will see if I can schedule a changeover to 13 and test and follow up.

Just a follow up and not to monopolize your time… I do appreciate it. Looking at the version switch, I now remember why I didn’t go to v13 in the first place… It was marked experimental. Is that still the case or has it stabilized? Not looking to hold you to it, just trying to get a general idea of the stability.

We say it’s experimental from a support side. But you can still test and switch back to 11.