Intermittant incoming issue: no audio received on the call

We are getting calls (and it seems like it is coming in batches) where the incoming calls are picked up but no audio is delivered (nobody hears anything). Then things start working again and everything is fine for a while. Really odd.

Logs for one example call (number was 9254550800):

[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [in@sub-record-check:1] NoOp(“SIP/voipms-00000099”, “Inbound Recording Check to 6468769215”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [in@sub-record-check:2] Set(“SIP/voipms-00000099”, “FROMEXTEN=unknown”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [in@sub-record-check:3] ExecIf(“SIP/voipms-00000099”, “10?Set(FROMEXTEN=9254550800)”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [in@sub-record-check:4] Gosub(“SIP/voipms-00000099”, “recordcheck,1(dontcare,in,6468769215)”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [recordcheck@sub-record-check:1] NoOp(“SIP/voipms-00000099”, “Starting recording check against dontcare”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [recordcheck@sub-record-check:2] Goto(“SIP/voipms-00000099”, “dontcare”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Goto (sub-record-check,recordcheck,3)
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [recordcheck@sub-record-check:3] Return(“SIP/voipms-00000099”, “”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [in@sub-record-check:5] Return(“SIP/voipms-00000099”, “”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [6468769215@from-trunk:3] Gosub(“SIP/voipms-00000099”, “app-blacklist-check,s,1()”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@app-blacklist-check:1] GotoIf(“SIP/voipms-00000099”, “0?blacklisted”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@app-blacklist-check:2] Set(“SIP/voipms-00000099”, “CALLED_BLACKLIST=1”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@app-blacklist-check:3] Return(“SIP/voipms-00000099”, “”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [6468769215@from-trunk:4] Set(“SIP/voipms-00000099”, “CDR(did)=6468769215”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [6468769215@from-trunk:5] ExecIf(“SIP/voipms-00000099”, “0 ?Set(CALLERID(name)=9254550800)”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [6468769215@from-trunk:6] Set(“SIP/voipms-00000099”, “CHANNEL(musicclass)=default”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [6468769215@from-trunk:7] Set(“SIP/voipms-00000099”, “__MOHCLASS=default”) in new stack
[2015-04-29 17:33:11] WARNING[13394][C-00000054] func_channel.c: Unknown or unavailable item requested: ‘reversecharge’
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [6468769215@from-trunk:8] GotoIf(“SIP/voipms-00000099”, “0?macro-hangupcall”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [6468769215@from-trunk:9] Set(“SIP/voipms-00000099”, “__CALLINGPRES_SV=allowed_not_screened”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [6468769215@from-trunk:10] Set(“SIP/voipms-00000099”, “CALLERPRES()=allowed_not_screened”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [6468769215@from-trunk:11] Goto(“SIP/voipms-00000099”, “ext-group,601,1”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Goto (ext-group,601,1)
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [601@ext-group:1] Macro(“SIP/voipms-00000099”, “user-callerid,”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-user-callerid:1] Set(“SIP/voipms-00000099”, “TOUCH_MONITOR=1430343191.153”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-user-callerid:2] Set(“SIP/voipms-00000099”, “AMPUSER=9254550800”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-user-callerid:3] GotoIf(“SIP/voipms-00000099”, “0?report”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-user-callerid:4] ExecIf(“SIP/voipms-00000099”, “1?Set(REALCALLERIDNUM=9254550800)”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-user-callerid:5] Set(“SIP/voipms-00000099”, “AMPUSER=”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/voipms-00000099”, “0?limit”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-user-callerid:7] Set(“SIP/voipms-00000099”, “AMPUSERCIDNAME=”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-user-callerid:8] GotoIf(“SIP/voipms-00000099”, “1?report”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Goto (macro-user-callerid,s,16)
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-user-callerid:16] GotoIf(“SIP/voipms-00000099”, “0?continue”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-user-callerid:17] ExecIf(“SIP/voipms-00000099”, “1?Set(__CALLEE_ACCOUNCODE=)”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-user-callerid:18] Set(“SIP/voipms-00000099”, “__TTL=64”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-user-callerid:19] GotoIf(“SIP/voipms-00000099”, “1?continue”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Goto (macro-user-callerid,s,30)
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-user-callerid:30] Set(“SIP/voipms-00000099”, “CALLERID(number)=9254550800”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-user-callerid:31] Set(“SIP/voipms-00000099”, “CALLERID(name)=+19254550800”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-user-callerid:32] Set(“SIP/voipms-00000099”, “CDR(cnum)=9254550800”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-user-callerid:33] Set(“SIP/voipms-00000099”, “CDR(cnam)=+19254550800”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-user-callerid:34] Set(“SIP/voipms-00000099”, “CHANNEL(language)=en”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [601@ext-group:2] Macro(“SIP/voipms-00000099”, “blkvm-setifempty,”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-blkvm-setifempty:1] GotoIf(“SIP/voipms-00000099”, “1?init”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Goto (macro-blkvm-setifempty,s,4)
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-blkvm-setifempty:4] Set(“SIP/voipms-00000099”, “__BLKVM_CHANNEL=SIP/voipms-00000099”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-blkvm-setifempty:5] Set(“SIP/voipms-00000099”, “SHARED(BLKVM,SIP/voipms-00000099)=TRUE”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-blkvm-setifempty:6] Set(“SIP/voipms-00000099”, “GOSUB_RETVAL=TRUE”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-blkvm-setifempty:7] MacroExit(“SIP/voipms-00000099”, “”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [601@ext-group:3] GotoIf(“SIP/voipms-00000099”, “1?skipov”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Goto (ext-group,601,6)
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [601@ext-group:6] Set(“SIP/voipms-00000099”, “RRNODEST=”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [601@ext-group:7] Set(“SIP/voipms-00000099”, “__NODEST=601”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [601@ext-group:8] GosubIf(“SIP/voipms-00000099”, “0?sub-rgsetcid,s,1()”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [601@ext-group:9] Gosub(“SIP/voipms-00000099”, “sub-record-check,s,1(rg,601,dontcare)”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@sub-record-check:1] GotoIf(“SIP/voipms-00000099”, “10?initialized”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Goto (sub-record-check,s,10)
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@sub-record-check:10] NoOp(“SIP/voipms-00000099”, “Recordings initialized”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@sub-record-check:11] ExecIf(“SIP/voipms-00000099”, “0?Set(ARG3=dontcare)”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@sub-record-check:12] Set(“SIP/voipms-00000099”, “REC_POLICY_MODE_SAVE=”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@sub-record-check:13] ExecIf(“SIP/voipms-00000099”, “0?Set(REC_STATUS=NO)”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@sub-record-check:14] GotoIf(“SIP/voipms-00000099”, “2?checkaction”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Goto (sub-record-check,s,17)
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@sub-record-check:17] GotoIf(“SIP/voipms-00000099”, “0?sub-record-check,rg,1”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@sub-record-check:18] NoOp(“SIP/voipms-00000099”, “Generic rg Recording Check - 9254550800 601”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@sub-record-check:19] Gosub(“SIP/voipms-00000099”, “recordcheck,1(dontcare,rg,601)”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [recordcheck@sub-record-check:1] NoOp(“SIP/voipms-00000099”, “Starting recording check against dontcare”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [recordcheck@sub-record-check:2] Goto(“SIP/voipms-00000099”, “dontcare”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Goto (sub-record-check,recordcheck,3)
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [recordcheck@sub-record-check:3] Return(“SIP/voipms-00000099”, “”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@sub-record-check:20] Return(“SIP/voipms-00000099”, “”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [601@ext-group:10] Set(“SIP/voipms-00000099”, “RingGroupMethod=memoryhunt”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [601@ext-group:11] Macro(“SIP/voipms-00000099”, “dial,20,Ttr,1000-1015”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-dial:1] GotoIf(“SIP/voipms-00000099”, “0?dial”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-dial:2] Set(“SIP/voipms-00000099”, “CHANNEL(musicclass)=default”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-dial:3] AGI(“SIP/voipms-00000099”, “dialparties.agi”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] res_agi.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] res_agi.c: dialparties.agi: Starting New Dialparties.agi
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] res_agi.c: dialparties.agi: Caller ID name is ‘+19254550800’ number is ‘9254550800’
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] res_agi.c: dialparties.agi: Methodology of ring is ‘memoryhunt’
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] res_agi.c: – dialparties.agi: Added extension 1000 to extension map
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] res_agi.c: – dialparties.agi: Added extension 1015 to extension map
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] res_agi.c: – dialparties.agi: Extension 1000 cf is disabled
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] res_agi.c: – dialparties.agi: Extension 1015 cf is disabled
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] res_agi.c: – dialparties.agi: Extension 1000 do not disturb is disabled
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] res_agi.c: – dialparties.agi: Extension 1015 do not disturb is disabled
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] res_agi.c: – dialparties.agi: Filtered ARG3: 1000-1015
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] res_agi.c: – <SIP/voipms-00000099>AGI Script dialparties.agi completed, returning 0
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-dial:20] NoOp(“SIP/voipms-00000099”, "Returned from dialparties with hunt groups to dial ") in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-dial:21] Set(“SIP/voipms-00000099”, “HuntLoop=0”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-dial:22] GotoIf(“SIP/voipms-00000099”, “1?a30”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Goto (macro-dial,s,26)
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-dial:26] Set(“SIP/voipms-00000099”, “HuntMember=HuntMember0”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-dial:27] GotoIf(“SIP/voipms-00000099”, “0?a32:a35”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Goto (macro-dial,s,31)
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-dial:31] GotoIf(“SIP/voipms-00000099”, “1?a36:a50”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Goto (macro-dial,s,32)
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-dial:32] Set(“SIP/voipms-00000099”, “CTLoop=0”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-dial:33] GotoIf(“SIP/voipms-00000099”, “0?a42”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-dial:34] Set(“SIP/voipms-00000099”, “CT_EXTEN=1000”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-dial:35] Set(“SIP/voipms-00000099”, “DB(CALLTRACE/1000)=9254550800”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-dial:36] Set(“SIP/voipms-00000099”, “CTLoop=1”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-dial:37] Goto(“SIP/voipms-00000099”, “s,a37”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Goto (macro-dial,s,33)
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-dial:33] GotoIf(“SIP/voipms-00000099”, “1?a42”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Goto (macro-dial,s,38)
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-dial:38] Dial(“SIP/voipms-00000099”, “SIP/1000,20,TtrM(auto-blkvm)”) in new stack
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] netsock2.c: == Using SIP RTP TOS bits 184
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] netsock2.c: == Using SIP RTP CoS mark 5
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] app_dial.c: – Called SIP/1000
[2015-04-29 17:33:11] VERBOSE[13394][C-00000054] app_dial.c: – SIP/1000-0000009a is ringing

[2015-04-29 17:33:22] VERBOSE[13394][C-00000054] app_dial.c: – SIP/1000-0000009a answered SIP/voipms-00000099
[2015-04-29 17:33:22] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-auto-blkvm:1] Set(“SIP/1000-0000009a”, “__MACRO_RESULT=”) in new stack
[2015-04-29 17:33:22] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-auto-blkvm:2] Set(“SIP/1000-0000009a”, “CFIGNORE=”) in new stack
[2015-04-29 17:33:22] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-auto-blkvm:3] Set(“SIP/1000-0000009a”, “MASTER_CHANNEL(CFIGNORE)=”) in new stack
[2015-04-29 17:33:22] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-auto-blkvm:4] Set(“SIP/1000-0000009a”, “FORWARD_CONTEXT=from-internal”) in new stack
[2015-04-29 17:33:22] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-auto-blkvm:5] Set(“SIP/1000-0000009a”, “MASTER_CHANNEL(FORWARD_CONTEXT)=from-internal”) in new stack
[2015-04-29 17:33:22] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-auto-blkvm:6] Macro(“SIP/1000-0000009a”, “blkvm-clr,”) in new stack
[2015-04-29 17:33:22] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-blkvm-clr:1] Set(“SIP/1000-0000009a”, “SHARED(BLKVM,SIP/voipms-00000099)=”) in new stack
[2015-04-29 17:33:22] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-blkvm-clr:2] Set(“SIP/1000-0000009a”, “GOSUB_RETVAL=”) in new stack
[2015-04-29 17:33:22] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-blkvm-clr:3] MacroExit(“SIP/1000-0000009a”, “”) in new stack
[2015-04-29 17:33:22] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-auto-blkvm:7] ExecIf(“SIP/1000-0000009a”, “0?Set(MASTER_CHANNEL(CONNECTEDLINE(num))=1000)”) in new stack
[2015-04-29 17:33:22] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-auto-blkvm:8] ExecIf(“SIP/1000-0000009a”, “0?Set(MASTER_CHANNEL(CONNECTEDLINE(name))=Front Desk)”) in new stack

[2015-04-29 17:33:32] VERBOSE[13394][C-00000054] pbx.c: – Executing [h@macro-dial:1] Macro(“SIP/voipms-00000099”, “hangupcall”) in new stack
[2015-04-29 17:33:32] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-hangupcall:1] ExecIf(“SIP/voipms-00000099”, “0?Set(CDR(recordingfile)=.wav)”) in new stack
[2015-04-29 17:33:32] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-hangupcall:2] GotoIf(“SIP/voipms-00000099”, “1?theend”) in new stack
[2015-04-29 17:33:32] VERBOSE[13394][C-00000054] pbx.c: – Goto (macro-hangupcall,s,4)
[2015-04-29 17:33:32] VERBOSE[13394][C-00000054] pbx.c: – Executing [s@macro-hangupcall:4] Hangup(“SIP/voipms-00000099”, “”) in new stack
[2015-04-29 17:33:32] VERBOSE[13394][C-00000054] app_macro.c: == Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘SIP/voipms-00000099’ in macro ‘hangupcall’
[2015-04-29 17:33:32] VERBOSE[13394][C-00000054] pbx.c: == Spawn extension (macro-dial, h, 1) exited non-zero on ‘SIP/voipms-00000099’
[2015-04-29 17:33:32] VERBOSE[13394][C-00000054] app_macro.c: == Spawn extension (macro-dial, s, 38) exited non-zero on ‘SIP/voipms-00000099’ in macro ‘dial’
[2015-04-29 17:33:32] VERBOSE[13394][C-00000054] pbx.c: == Spawn extension (ext-group, 601, 11) exited non-zero on ‘SIP/voipms-00000099’

[2015-04-29 17:33:38] VERBOSE[2337][C-00000055] netsock2.c: == Using SIP RTP TOS bits 184
[2015-04-29 17:33:38] VERBOSE[2337][C-00000055] netsock2.c: == Using SIP RTP CoS mark 5
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [6468769215@from-trunk:1] Set(“SIP/voipms-0000009b”, “__FROM_DID=6468769215”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [6468769215@from-trunk:2] Gosub(“SIP/voipms-0000009b”, “sub-record-check,s,1(in,6468769215,dontcare)”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@sub-record-check:1] GotoIf(“SIP/voipms-0000009b”, “0?initialized”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@sub-record-check:2] Set(“SIP/voipms-0000009b”, “__REC_STATUS=INITIALIZED”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@sub-record-check:3] Set(“SIP/voipms-0000009b”, “NOW=1430343218”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@sub-record-check:4] Set(“SIP/voipms-0000009b”, “__DAY=29”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@sub-record-check:5] Set(“SIP/voipms-0000009b”, “__MONTH=04”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@sub-record-check:6] Set(“SIP/voipms-0000009b”, “__YEAR=2015”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@sub-record-check:7] Set(“SIP/voipms-0000009b”, “__TIMESTR=20150429-173338”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@sub-record-check:8] Set(“SIP/voipms-0000009b”, “__FROMEXTEN=unknown”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@sub-record-check:9] Set(“SIP/voipms-0000009b”, “__MON_FMT=wav”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@sub-record-check:10] NoOp(“SIP/voipms-0000009b”, “Recordings initialized”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@sub-record-check:11] ExecIf(“SIP/voipms-0000009b”, “0?Set(ARG3=dontcare)”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@sub-record-check:12] Set(“SIP/voipms-0000009b”, “REC_POLICY_MODE_SAVE=”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@sub-record-check:13] ExecIf(“SIP/voipms-0000009b”, “0?Set(REC_STATUS=NO)”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@sub-record-check:14] GotoIf(“SIP/voipms-0000009b”, “2?checkaction”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Goto (sub-record-check,s,17)
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@sub-record-check:17] GotoIf(“SIP/voipms-0000009b”, “1?sub-record-check,in,1”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Goto (sub-record-check,in,1)

More logs:

[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [in@sub-record-check:1] NoOp(“SIP/voipms-0000009b”, “Inbound Recording Check to 6468769215”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [in@sub-record-check:2] Set(“SIP/voipms-0000009b”, “FROMEXTEN=unknown”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [in@sub-record-check:3] ExecIf(“SIP/voipms-0000009b”, “10?Set(FROMEXTEN=9254550800)”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [in@sub-record-check:4] Gosub(“SIP/voipms-0000009b”, “recordcheck,1(dontcare,in,6468769215)”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [recordcheck@sub-record-check:1] NoOp(“SIP/voipms-0000009b”, “Starting recording check against dontcare”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [recordcheck@sub-record-check:2] Goto(“SIP/voipms-0000009b”, “dontcare”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Goto (sub-record-check,recordcheck,3)
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [recordcheck@sub-record-check:3] Return(“SIP/voipms-0000009b”, “”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [in@sub-record-check:5] Return(“SIP/voipms-0000009b”, “”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [6468769215@from-trunk:3] Gosub(“SIP/voipms-0000009b”, “app-blacklist-check,s,1()”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@app-blacklist-check:1] GotoIf(“SIP/voipms-0000009b”, “0?blacklisted”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@app-blacklist-check:2] Set(“SIP/voipms-0000009b”, “CALLED_BLACKLIST=1”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@app-blacklist-check:3] Return(“SIP/voipms-0000009b”, “”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [6468769215@from-trunk:4] Set(“SIP/voipms-0000009b”, “CDR(did)=6468769215”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [6468769215@from-trunk:5] ExecIf(“SIP/voipms-0000009b”, “0 ?Set(CALLERID(name)=9254550800)”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [6468769215@from-trunk:6] Set(“SIP/voipms-0000009b”, “CHANNEL(musicclass)=default”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [6468769215@from-trunk:7] Set(“SIP/voipms-0000009b”, “__MOHCLASS=default”) in new stack
[2015-04-29 17:33:38] WARNING[13405][C-00000055] func_channel.c: Unknown or unavailable item requested: ‘reversecharge’
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [6468769215@from-trunk:8] GotoIf(“SIP/voipms-0000009b”, “0?macro-hangupcall”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [6468769215@from-trunk:9] Set(“SIP/voipms-0000009b”, “__CALLINGPRES_SV=allowed_not_screened”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [6468769215@from-trunk:10] Set(“SIP/voipms-0000009b”, “CALLERPRES()=allowed_not_screened”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [6468769215@from-trunk:11] Goto(“SIP/voipms-0000009b”, “ext-group,601,1”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Goto (ext-group,601,1)
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [601@ext-group:1] Macro(“SIP/voipms-0000009b”, “user-callerid,”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-user-callerid:1] Set(“SIP/voipms-0000009b”, “TOUCH_MONITOR=1430343218.155”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-user-callerid:2] Set(“SIP/voipms-0000009b”, “AMPUSER=9254550800”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-user-callerid:3] GotoIf(“SIP/voipms-0000009b”, “0?report”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-user-callerid:4] ExecIf(“SIP/voipms-0000009b”, “1?Set(REALCALLERIDNUM=9254550800)”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-user-callerid:5] Set(“SIP/voipms-0000009b”, “AMPUSER=”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-user-callerid:6] GotoIf(“SIP/voipms-0000009b”, “0?limit”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-user-callerid:7] Set(“SIP/voipms-0000009b”, “AMPUSERCIDNAME=”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-user-callerid:8] GotoIf(“SIP/voipms-0000009b”, “1?report”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Goto (macro-user-callerid,s,16)
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-user-callerid:16] GotoIf(“SIP/voipms-0000009b”, “0?continue”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-user-callerid:17] ExecIf(“SIP/voipms-0000009b”, “1?Set(__CALLEE_ACCOUNCODE=)”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-user-callerid:18] Set(“SIP/voipms-0000009b”, “__TTL=64”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-user-callerid:19] GotoIf(“SIP/voipms-0000009b”, “1?continue”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Goto (macro-user-callerid,s,30)
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-user-callerid:30] Set(“SIP/voipms-0000009b”, “CALLERID(number)=9254550800”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-user-callerid:31] Set(“SIP/voipms-0000009b”, “CALLERID(name)=+19254550800”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-user-callerid:32] Set(“SIP/voipms-0000009b”, “CDR(cnum)=9254550800”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-user-callerid:33] Set(“SIP/voipms-0000009b”, “CDR(cnam)=+19254550800”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-user-callerid:34] Set(“SIP/voipms-0000009b”, “CHANNEL(language)=en”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [601@ext-group:2] Macro(“SIP/voipms-0000009b”, “blkvm-setifempty,”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-blkvm-setifempty:1] GotoIf(“SIP/voipms-0000009b”, “1?init”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Goto (macro-blkvm-setifempty,s,4)
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-blkvm-setifempty:4] Set(“SIP/voipms-0000009b”, “__BLKVM_CHANNEL=SIP/voipms-0000009b”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-blkvm-setifempty:5] Set(“SIP/voipms-0000009b”, “SHARED(BLKVM,SIP/voipms-0000009b)=TRUE”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-blkvm-setifempty:6] Set(“SIP/voipms-0000009b”, “GOSUB_RETVAL=TRUE”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-blkvm-setifempty:7] MacroExit(“SIP/voipms-0000009b”, “”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [601@ext-group:3] GotoIf(“SIP/voipms-0000009b”, “1?skipov”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Goto (ext-group,601,6)
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [601@ext-group:6] Set(“SIP/voipms-0000009b”, “RRNODEST=”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [601@ext-group:7] Set(“SIP/voipms-0000009b”, “__NODEST=601”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [601@ext-group:8] GosubIf(“SIP/voipms-0000009b”, “0?sub-rgsetcid,s,1()”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [601@ext-group:9] Gosub(“SIP/voipms-0000009b”, “sub-record-check,s,1(rg,601,dontcare)”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@sub-record-check:1] GotoIf(“SIP/voipms-0000009b”, “10?initialized”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Goto (sub-record-check,s,10)
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@sub-record-check:10] NoOp(“SIP/voipms-0000009b”, “Recordings initialized”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@sub-record-check:11] ExecIf(“SIP/voipms-0000009b”, “0?Set(ARG3=dontcare)”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@sub-record-check:12] Set(“SIP/voipms-0000009b”, “REC_POLICY_MODE_SAVE=”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@sub-record-check:13] ExecIf(“SIP/voipms-0000009b”, “0?Set(REC_STATUS=NO)”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@sub-record-check:14] GotoIf(“SIP/voipms-0000009b”, “2?checkaction”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Goto (sub-record-check,s,17)
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@sub-record-check:17] GotoIf(“SIP/voipms-0000009b”, “0?sub-record-check,rg,1”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@sub-record-check:18] NoOp(“SIP/voipms-0000009b”, “Generic rg Recording Check - 9254550800 601”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@sub-record-check:19] Gosub(“SIP/voipms-0000009b”, “recordcheck,1(dontcare,rg,601)”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [recordcheck@sub-record-check:1] NoOp(“SIP/voipms-0000009b”, “Starting recording check against dontcare”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [recordcheck@sub-record-check:2] Goto(“SIP/voipms-0000009b”, “dontcare”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Goto (sub-record-check,recordcheck,3)
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [recordcheck@sub-record-check:3] Return(“SIP/voipms-0000009b”, “”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@sub-record-check:20] Return(“SIP/voipms-0000009b”, “”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [601@ext-group:10] Set(“SIP/voipms-0000009b”, “RingGroupMethod=memoryhunt”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [601@ext-group:11] Macro(“SIP/voipms-0000009b”, “dial,20,Ttr,1000-1015”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-dial:1] GotoIf(“SIP/voipms-0000009b”, “0?dial”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-dial:2] Set(“SIP/voipms-0000009b”, “CHANNEL(musicclass)=default”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-dial:3] AGI(“SIP/voipms-0000009b”, “dialparties.agi”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] res_agi.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] res_agi.c: dialparties.agi: Starting New Dialparties.agi
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] res_agi.c: dialparties.agi: Caller ID name is ‘+19254550800’ number is ‘9254550800’
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] res_agi.c: dialparties.agi: Methodology of ring is ‘memoryhunt’
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] res_agi.c: – dialparties.agi: Added extension 1000 to extension map
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] res_agi.c: – dialparties.agi: Added extension 1015 to extension map
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] res_agi.c: – dialparties.agi: Extension 1000 cf is disabled
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] res_agi.c: – dialparties.agi: Extension 1015 cf is disabled
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] res_agi.c: – dialparties.agi: Extension 1000 do not disturb is disabled
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] res_agi.c: – dialparties.agi: Extension 1015 do not disturb is disabled
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] res_agi.c: – dialparties.agi: Filtered ARG3: 1000-1015
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] res_agi.c: – <SIP/voipms-0000009b>AGI Script dialparties.agi completed, returning 0
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-dial:20] NoOp(“SIP/voipms-0000009b”, "Returned from dialparties with hunt groups to dial ") in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-dial:21] Set(“SIP/voipms-0000009b”, “HuntLoop=0”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-dial:22] GotoIf(“SIP/voipms-0000009b”, “1?a30”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Goto (macro-dial,s,26)
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-dial:26] Set(“SIP/voipms-0000009b”, “HuntMember=HuntMember0”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-dial:27] GotoIf(“SIP/voipms-0000009b”, “0?a32:a35”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Goto (macro-dial,s,31)
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-dial:31] GotoIf(“SIP/voipms-0000009b”, “1?a36:a50”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Goto (macro-dial,s,32)
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-dial:32] Set(“SIP/voipms-0000009b”, “CTLoop=0”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-dial:33] GotoIf(“SIP/voipms-0000009b”, “0?a42”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-dial:34] Set(“SIP/voipms-0000009b”, “CT_EXTEN=1000”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-dial:35] Set(“SIP/voipms-0000009b”, “DB(CALLTRACE/1000)=9254550800”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-dial:36] Set(“SIP/voipms-0000009b”, “CTLoop=1”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-dial:37] Goto(“SIP/voipms-0000009b”, “s,a37”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Goto (macro-dial,s,33)
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-dial:33] GotoIf(“SIP/voipms-0000009b”, “1?a42”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Goto (macro-dial,s,38)
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-dial:38] Dial(“SIP/voipms-0000009b”, “SIP/1000,20,TtrM(auto-blkvm)”) in new stack
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] netsock2.c: == Using SIP RTP TOS bits 184
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] netsock2.c: == Using SIP RTP CoS mark 5
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] app_dial.c: – Called SIP/1000
[2015-04-29 17:33:38] VERBOSE[13405][C-00000055] app_dial.c: – SIP/1000-0000009c is ringing

[2015-04-29 17:33:43] VERBOSE[13405][C-00000055] app_dial.c: – SIP/1000-0000009c answered SIP/voipms-0000009b
[2015-04-29 17:33:43] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-auto-blkvm:1] Set(“SIP/1000-0000009c”, “__MACRO_RESULT=”) in new stack
[2015-04-29 17:33:43] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-auto-blkvm:2] Set(“SIP/1000-0000009c”, “CFIGNORE=”) in new stack
[2015-04-29 17:33:43] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-auto-blkvm:3] Set(“SIP/1000-0000009c”, “MASTER_CHANNEL(CFIGNORE)=”) in new stack
[2015-04-29 17:33:43] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-auto-blkvm:4] Set(“SIP/1000-0000009c”, “FORWARD_CONTEXT=from-internal”) in new stack
[2015-04-29 17:33:43] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-auto-blkvm:5] Set(“SIP/1000-0000009c”, “MASTER_CHANNEL(FORWARD_CONTEXT)=from-internal”) in new stack
[2015-04-29 17:33:43] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-auto-blkvm:6] Macro(“SIP/1000-0000009c”, “blkvm-clr,”) in new stack
[2015-04-29 17:33:43] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-blkvm-clr:1] Set(“SIP/1000-0000009c”, “SHARED(BLKVM,SIP/voipms-0000009b)=”) in new stack
[2015-04-29 17:33:43] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-blkvm-clr:2] Set(“SIP/1000-0000009c”, “GOSUB_RETVAL=”) in new stack
[2015-04-29 17:33:43] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-blkvm-clr:3] MacroExit(“SIP/1000-0000009c”, “”) in new stack
[2015-04-29 17:33:43] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-auto-blkvm:7] ExecIf(“SIP/1000-0000009c”, “0?Set(MASTER_CHANNEL(CONNECTEDLINE(num))=1000)”) in new stack
[2015-04-29 17:33:43] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-auto-blkvm:8] ExecIf(“SIP/1000-0000009c”, “0?Set(MASTER_CHANNEL(CONNECTEDLINE(name))=Front Desk)”) in new stack

[2015-04-29 17:34:00] VERBOSE[13405][C-00000055] pbx.c: – Executing [h@macro-dial:1] Macro(“SIP/voipms-0000009b”, “hangupcall”) in new stack
[2015-04-29 17:34:00] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-hangupcall:1] ExecIf(“SIP/voipms-0000009b”, “0?Set(CDR(recordingfile)=.wav)”) in new stack
[2015-04-29 17:34:00] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-hangupcall:2] GotoIf(“SIP/voipms-0000009b”, “1?theend”) in new stack
[2015-04-29 17:34:00] VERBOSE[13405][C-00000055] pbx.c: – Goto (macro-hangupcall,s,4)
[2015-04-29 17:34:00] VERBOSE[13405][C-00000055] pbx.c: – Executing [s@macro-hangupcall:4] Hangup(“SIP/voipms-0000009b”, “”) in new stack
[2015-04-29 17:34:00] VERBOSE[13405][C-00000055] app_macro.c: == Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘SIP/voipms-0000009b’ in macro ‘hangupcall’
[2015-04-29 17:34:00] VERBOSE[13405][C-00000055] pbx.c: == Spawn extension (macro-dial, h, 1) exited non-zero on ‘SIP/voipms-0000009b’
[2015-04-29 17:34:00] VERBOSE[13405][C-00000055] app_macro.c: == Spawn extension (macro-dial, s, 38) exited non-zero on ‘SIP/voipms-0000009b’ in macro ‘dial’
[2015-04-29 17:34:00] VERBOSE[13405][C-00000055] pbx.c: == Spawn extension (ext-group, 601, 11) exited non-zero on ‘SIP/voipms-0000009b’