Fax extension not answering in 15 seconds

Hello,

Due to a uncontrolled shutdown my server had become corrupt. Resolution was to reinstall the system. As I did this I chose the latest version I could find for the BeagleBoneBlack.
Installation runs now FreePBX 12.0.76 with asterisk 11.18.0.
In the old config with IncrediblePBX11-rasp I was able to get the fax to work, but now with these latest version an incoming fax is detected and send to the fax-extension. But the problem is that I receive the message “sorry an error has occurred” when I make an internal call. This error has to do I think because there is no voicemail config for the fax-extension and I didn’t think this was necessary. From external it looks like it is just not answered after the redirection towards the fax.
Should the extension somewhere be set to autoanswer??

Below the trace from external.

John

Trace from external-faxservice:

   == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
    -- Executing [[email protected]:1] Set("SIP/mydivert-00000f46", "GROUP()=OUT_3") in new stack
    -- Executing [[email protected]:2] Goto("SIP/mydivert-00000f46", "from-trunk,1956XXXXXXX,1") in new stack
    -- Goto (from-trunk,1956XXXXXXX,1)
    -- Executing [[email protected]:1] Set("SIP/mydivert-00000f46", "__FROM_DID=1956XXXXXXX") in new stack
    -- Executing [[email protected]:2] Set("SIP/mydivert-00000f46", "CIDSFSCHEME=QUxMfEFMTA==") in new stack
    -- Executing [[email protected]:3] AGI("SIP/mydivert-00000f46", "/var/www/html/admin/modules/superfecta/agi/superfecta.agi") in new stack
    -- Launched AGI Script /var/www/html/admin/modules/superfecta/agi/superfecta.agi
 /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta is Answering the Channel
 /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: Scheme is ALL
 /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: The DID passed from Asterisk is: 1956XXXXXXX
 /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: The number passed from Asterisk is: 4420XXXXXXX
 /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: The CID name passed from Asterisk is: 44203XXXXXXX
 /var/www/html/admin/modules/superfecta/agi/superfecta.agi: CID Superfecta: Executing Scheme..
    -- <SIP/mydivert-00000f46>AGI Script /var/www/html/admin/modules/superfecta/agi/superfecta.agi completed, returning 0
    -- Executing [[email protected]:4] Set("SIP/mydivert-00000f46", "CALLERID(name)=") in new stack
    -- Executing [[email protected]:5] Gosub("SIP/mydivert-00000f46", "sub-record-check,s,1(in,1956XXXXXXX,dontcare)") in new stack
    -- Executing [[email protected]:1] GotoIf("SIP/mydivert-00000f46", "0?initialized") in new stack
    -- Executing [[email protected]:2] Set("SIP/mydivert-00000f46", "__REC_STATUS=INITIALIZED") in new stack
    -- Executing [[email protected]:3] Set("SIP/mydivert-00000f46", "NOW=1442501226") in new stack
    -- Executing [[email protected]:4] Set("SIP/mydivert-00000f46", "__DAY=17") in new stack
    -- Executing [[email protected]:5] Set("SIP/mydivert-00000f46", "__MONTH=09") in new stack
    -- Executing [[email protected]:6] Set("SIP/mydivert-00000f46", "__YEAR=2015") in new stack
    -- Executing [[email protected]:7] Set("SIP/mydivert-00000f46", "__TIMESTR=20150917-094706") in new stack
    -- Executing [[email protected]:8] Set("SIP/mydivert-00000f46", "__FROMEXTEN=unknown") in new stack
    -- Executing [[email protected]:9] Set("SIP/mydivert-00000f46", "__MON_FMT=wav") in new stack
    -- Executing [[email protected]:10] NoOp("SIP/mydivert-00000f46", "Recordings initialized") in new stack
    -- Executing [[email protected]:11] ExecIf("SIP/mydivert-00000f46", "0?Set(ARG3=dontcare)") in new stack
    -- Executing [[email protected]:12] Set("SIP/mydivert-00000f46", "REC_POLICY_MODE_SAVE=") in new stack
    -- Executing [[email protected]:13] ExecIf("SIP/mydivert-00000f46", "0?Set(REC_STATUS=NO)") in new stack
    -- Executing [[email protected]:14] GotoIf("SIP/mydivert-00000f46", "2?checkaction") in new stack
    -- Goto (sub-record-check,s,17)
    -- Executing [[email protected]:17] GotoIf("SIP/mydivert-00000f46", "1?sub-record-check,in,1") in new stack
    -- Goto (sub-record-check,in,1)
    -- Executing [[email protected]:1] NoOp("SIP/mydivert-00000f46", "Inbound Recording Check to 1956XXXXXXX") in new stack
    -- Executing [[email protected]:2] Set("SIP/mydivert-00000f46", "FROMEXTEN=unknown") in new stack
    -- Executing [[email protected]:3] ExecIf("SIP/mydivert-00000f46", "12?Set(FROMEXTEN=44203XXXXXXX)") in new stack
    -- Executing [[email protected]:4] Gosub("SIP/mydivert-00000f46", "recordcheck,1(dontcare,in,1956XXXXXXX)") in new stack
    -- Executing [[email protected]:1] NoOp("SIP/mydivert-00000f46", "Starting recording check against dontcare") in new stack
    -- Executing [[email protected]:2] Goto("SIP/mydivert-00000f46", "dontcare") in new stack
    -- Goto (sub-record-check,recordcheck,3)
    -- Executing [[email protected]:3] Return("SIP/mydivert-00000f46", "") in new stack
    -- Executing [[email protected]:5] Return("SIP/mydivert-00000f46", "") in new stack
    -- Executing [[email protected]:6] Gosub("SIP/mydivert-00000f46", "cidlookup,cidlookup_1,1()") in new stack
    -- Executing [[email protected]:1] Set("SIP/mydivert-00000f46", "CURLOPT(httptimeout)=7") in new stack
    -- Executing [[email protected]:2] Set("SIP/mydivert-00000f46", "CALLERID(name)=") in new stack
    -- Executing [[email protected]:3] Set("SIP/mydivert-00000f46", "current_hour=2015-09-17 09") in new stack
    -- Executing [[email protected]:4] Set("SIP/mydivert-00000f46", "last_query_hour=2015-09-16 11") in new stack
    -- Executing [[email protected]:5] Set("SIP/mydivert-00000f46", "total_hourly_queries=3") in new stack
    -- Executing [[email protected]:6] ExecIf("SIP/mydivert-00000f46", "1?Set(DB(cidlookup/opencnam_total_hourly_queries)=0)") in new stack
    -- Executing [[email protected]:7] ExecIf("SIP/mydivert-00000f46", "0?Set(DB(cidlookup/opencnam_total_hourly_queries)=0)") in new stack
    -- Executing [[email protected]:8] Set("SIP/mydivert-00000f46", "DB(cidlookup/opencnam_total_hourly_queries)=1") in new stack
    -- Executing [[email protected]:9] ExecIf("SIP/mydivert-00000f46", "0?System(/var/lib/asterisk/bin/opencnam-alert.php)") in new stack
    -- Executing [[email protected]:10] Set("SIP/mydivert-00000f46", "DB(cidlookup/opencnam_last_query_hour)=2015-09-17 09") in new stack
    -- Executing [[email protected]:11] Return("SIP/mydivert-00000f46", "") in new stack
    -- Executing [[email protected]:7] Gosub("SIP/mydivert-00000f46", "app-blacklist-check,s,1()") in new stack
    -- Executing [[email protected]:1] GotoIf("SIP/mydivert-00000f46", "0?blacklisted") in new stack
    -- Executing [[email protected]:2] Set("SIP/mydivert-00000f46", "CALLED_BLACKLIST=1") in new stack
    -- Executing [[email protected]:3] Return("SIP/mydivert-00000f46", "") in new stack
    -- Executing [[email protected]:8] Set("SIP/mydivert-00000f46", "CDR(did)=1956XXXXXXX") in new stack
    -- Executing [[email protected]:9] ExecIf("SIP/mydivert-00000f46", "1 ?Set(CALLERID(name)=44203XXXXXXX)") in new stack
    -- Executing [[email protected]:10] Set("SIP/mydivert-00000f46", "CHANNEL(musicclass)=default") in new stack
    -- Executing [[email protected]:11] Set("SIP/mydivert-00000f46", "__MOHCLASS=default") in new stack
[2015-09-17 09:47:08] WARNING[32115][C-00000fa9]: func_channel.c:538 func_channel_read: Unknown or unavailable item requested: 'reversecharge'
    -- Executing [[email protected]:12] GotoIf("SIP/mydivert-00000f46", "0?macro-hangupcall") in new stack
    -- Executing [[email protected]:13] Set("SIP/mydivert-00000f46", "__CALLINGPRES_SV=allowed_not_screened") in new stack
    -- Executing [[email protected]:14] Set("SIP/mydivert-00000f46", "CALLERPRES()=allowed_not_screened") in new stack
    -- Executing [[email protected]:15] Set("SIP/mydivert-00000f46", "FAX_DEST=from-did-direct^329^1") in new stack
    -- Executing [[email protected]:16] Set("SIP/mydivert-00000f46", "FAXOPT(faxdetect)=yes") in new stack
    -- Executing [[email protected]:17] Answer("SIP/mydivert-00000f46", "") in new stack
    -- Executing [[email protected]:18] Wait("SIP/mydivert-00000f46", "4") in new stack
       > 0xb2b097e8 -- Probation passed - setting RTP source address to 109.68.162.233:13790
  == Redirecting 'SIP/mydivert-00000f46' to fax extension due to CNG detection
  == Spawn extension (from-trunk, fax, 1) exited non-zero on 'SIP/mydivert-00000f46'
    -- Executing [[email protected]:1] Goto("SIP/mydivert-00000f46", "from-did-direct,329,1") in new stack
    -- Goto (from-did-direct,329,1)
    -- Executing [[email protected]:1] Set("SIP/mydivert-00000f46", "__RINGTIMER=15") in new stack
    -- Executing [[email protected]:2] Macro("SIP/mydivert-00000f46", "exten-vm,329,329,0,0,0") in new stack
    -- Executing [[email protected]:1] Macro("SIP/mydivert-00000f46", "user-callerid,") in new stack
    -- Executing [[email protected]:1] Set("SIP/mydivert-00000f46", "TOUCH_MONITOR=1442501225.4154") in new stack
    -- Executing [[email protected]:2] Set("SIP/mydivert-00000f46", "AMPUSER=44203XXXXXXX") in new stack
    -- Executing [[email protected]:3] GotoIf("SIP/mydivert-00000f46", "0?report") in new stack
    -- Executing [[email protected]:4] ExecIf("SIP/mydivert-00000f46", "1?Set(REALCALLERIDNUM=44203XXXXXXX)") in new stack
    -- Executing [[email protected]:5] Set("SIP/mydivert-00000f46", "AMPUSER=") in new stack
    -- Executing [[email protected]:6] GotoIf("SIP/mydivert-00000f46", "0?limit") in new stack
    -- Executing [[email protected]:7] Set("SIP/mydivert-00000f46", "AMPUSERCIDNAME=") in new stack
    -- Executing [[email protected]:8] GotoIf("SIP/mydivert-00000f46", "1?report") in new stack
    -- Goto (macro-user-callerid,s,14)
    -- Executing [[email protected]:14] GotoIf("SIP/mydivert-00000f46", "0?continue") in new stack
    -- Executing [[email protected]:15] Set("SIP/mydivert-00000f46", "__TTL=64") in new stack
    -- Executing [[email protected]:16] GotoIf("SIP/mydivert-00000f46", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,27)
    -- Executing [[email protected]:27] Set("SIP/mydivert-00000f46", "CALLERID(number)=44203XXXXXXXX") in new stack
    -- Executing [[email protected]:28] Set("SIP/mydivert-00000f46", "CALLERID(name)=44203XXXXXXX") in new stack
    -- Executing [[email protected]:29] Set("SIP/mydivert-00000f46", "CDR(cnum)=44203XXXXXXX") in new stack
    -- Executing [[email protected]:30] Set("SIP/mydivert-00000f46", "CDR(cnam)=44203XXXXXXX") in new stack
    -- Executing [[email protected]:31] Set("SIP/mydivert-00000f46", "CHANNEL(language)=en") in new stack
    -- Executing [[email protected]:2] Set("SIP/mydivert-00000f46", "RingGroupMethod=none") in new stack
    -- Executing [[email protected]:3] Set("SIP/mydivert-00000f46", "__EXTTOCALL=329") in new stack
    -- Executing [[email protected]:4] Set("SIP/mydivert-00000f46", "__PICKUPMARK=329") in new stack
    -- Executing [[email protected]:5] Set("SIP/mydivert-00000f46", "RT=15") in new stack
    -- Executing [[email protected]:6] Gosub("SIP/mydivert-00000f46", "sub-record-check,s,1(exten,329,dontcare)") in new stack
    -- Executing [[email protected]:1] GotoIf("SIP/mydivert-00000f46", "12?initialized") in new stack
    -- Goto (sub-record-check,s,10)
    -- Executing [[email protected]:10] NoOp("SIP/mydivert-00000f46", "Recordings initialized") in new stack
    -- Executing [[email protected]:11] ExecIf("SIP/mydivert-00000f46", "0?Set(ARG3=dontcare)") in new stack
    -- Executing [[email protected]:12] Set("SIP/mydivert-00000f46", "REC_POLICY_MODE_SAVE=") in new stack
    -- Executing [[email protected]:13] ExecIf("SIP/mydivert-00000f46", "0?Set(REC_STATUS=NO)") in new stack
    -- Executing [[email protected]:14] GotoIf("SIP/mydivert-00000f46", "5?checkaction") in new stack
    -- Goto (sub-record-check,s,17)
    -- Executing [[email protected]:17] GotoIf("SIP/mydivert-00000f46", "1?sub-record-check,exten,1") in new stack
    -- Goto (sub-record-check,exten,1)
    -- Executing [[email protected]:1] NoOp("SIP/mydivert-00000f46", "Exten Recording Check between 44203XXXXXXX and 329") in new stack
    -- Executing [[email protected]:2] Set("SIP/mydivert-00000f46", "CALLTYPE=external") in new stack
    -- Executing [[email protected]:3] ExecIf("SIP/mydivert-00000f46", "0?Set(CALLTYPE=)") in new stack
    -- Executing [[email protected]:4] Set("SIP/mydivert-00000f46", "CALLEE=dontcare") in new stack
    -- Executing [[email protected]:5] ExecIf("SIP/mydivert-00000f46", "0?Set(CALLEE=dontcare)") in new stack
    -- Executing [[email protected]:6] GotoIf("SIP/mydivert-00000f46", "1?callee") in new stack
    -- Goto (sub-record-check,exten,11)
    -- Executing [[email protected]:11] Gosub("SIP/mydivert-00000f46", "recordcheck,1(dontcare,external,329)") in new stack
    -- Executing [[email protected]:1] NoOp("SIP/mydivert-00000f46", "Starting recording check against dontcare") in new stack
    -- Executing [[email protected]:2] Goto("SIP/mydivert-00000f46", "dontcare") in new stack
    -- Goto (sub-record-check,recordcheck,3)
    -- Executing [[email protected]:3] Return("SIP/mydivert-00000f46", "") in new stack
    -- Executing [[email protected]:12] Return("SIP/mydivert-00000f46", "") in new stack
    -- Executing [[email protected]:7] GotoIf("SIP/mydivert-00000f46", "1?macrodial") in new stack
    -- Goto (macro-exten-vm,s,13)
    -- Executing [[email protected]:13] GosubIf("SIP/mydivert-00000f46", "0?clrheader,1()") in new stack
    -- Executing [[email protected]:14] Macro("SIP/mydivert-00000f46", "dial-one,15,Ttr,329") in new stack
    -- Executing [[email protected]:1] Set("SIP/mydivert-00000f46", "DEXTEN=329") in new stack
    -- Executing [[email protected]:2] Set("SIP/mydivert-00000f46", "DIALSTATUS_CW=") in new stack
    -- Executing [[email protected]:3] GosubIf("SIP/mydivert-00000f46", "0?screen,1()") in new stack
    -- Executing [[email protected]:4] GosubIf("SIP/mydivert-00000f46", "0?cf,1()") in new stack
    -- Executing [[email protected]:5] GotoIf("SIP/mydivert-00000f46", "1?skip1") in new stack
    -- Goto (macro-dial-one,s,8)
    -- Executing [[email protected]:8] GotoIf("SIP/mydivert-00000f46", "0?nodial") in new stack
    -- Executing [[email protected]:9] GotoIf("SIP/mydivert-00000f46", "0?continue") in new stack
    -- Executing [[email protected]:10] Set("SIP/mydivert-00000f46", "EXTHASCW=ENABLED") in new stack
    -- Executing [[email protected]:11] GotoIf("SIP/mydivert-00000f46", "0?next1:cwinusebusy") in new stack
    -- Goto (macro-dial-one,s,23)
    -- Executing [[email protected]:23] GotoIf("SIP/mydivert-00000f46", "1?next3:continue") in new stack
    -- Goto (macro-dial-one,s,24)
    -- Executing [[email protected]:24] ExecIf("SIP/mydivert-00000f46", "0?Set(DIALSTATUS_CW=BUSY)") in new stack
    -- Executing [[email protected]:25] GotoIf("SIP/mydivert-00000f46", "0?nodial") in new stack
    -- Executing [[email protected]:26] GosubIf("SIP/mydivert-00000f46", "1?dstring,1():dlocal,1()") in new stack
    -- Executing [[email protected]:1] Set("SIP/mydivert-00000f46", "DSTRING=") in new stack
    -- Executing [[email protected]:2] Set("SIP/mydivert-00000f46", "DEVICES=329") in new stack
    -- Executing [[email protected]:3] ExecIf("SIP/mydivert-00000f46", "0?Return()") in new stack
    -- Executing [[email protected]:4] ExecIf("SIP/mydivert-00000f46", "0?Set(DEVICES=29)") in new stack
    -- Executing [[email protected]:5] Set("SIP/mydivert-00000f46", "LOOPCNT=1") in new stack
    -- Executing [[email protected]:6] Set("SIP/mydivert-00000f46", "ITER=1") in new stack
    -- Executing [[email protected]:7] Set("SIP/mydivert-00000f46", "THISDIAL=IAX2/329") in new stack
    -- Executing [[email protected]:8] GosubIf("SIP/mydivert-00000f46", "1?zap2dahdi,1()") in new stack
    -- Executing [[email protected]:1] ExecIf("SIP/mydivert-00000f46", "0?Return()") in new stack
    -- Executing [[email protected]:2] Set("SIP/mydivert-00000f46", "NEWDIAL=") in new stack
    -- Executing [[email protected]:3] Set("SIP/mydivert-00000f46", "LOOPCNT2=1") in new stack
    -- Executing [[email protected]:4] Set("SIP/mydivert-00000f46", "ITER2=1") in new stack
    -- Executing [[email protected]:5] Set("SIP/mydivert-00000f46", "THISPART2=IAX2/329") in new stack
    -- Executing [[email protected]:6] ExecIf("SIP/mydivert-00000f46", "0?Set(THISPART2=DAHDI2/329)") in new stack
    -- Executing [z[email protected]:7] Set("SIP/mydivert-00000f46", "NEWDIAL=IAX2/329&") in new stack
    -- Executing [[email protected]:8] Set("SIP/mydivert-00000f46", "ITER2=2") in new stack
    -- Executing [[email protected]:9] GotoIf("SIP/mydivert-00000f46", "0?begin2") in new stack
    -- Executing [[email protected]:10] Set("SIP/mydivert-00000f46", "THISDIAL=IAX2/329") in new stack
    -- Executing [[email protected]:11] Return("SIP/mydivert-00000f46", "") in new stack
    -- Executing [[email protected]:9] GotoIf("SIP/mydivert-00000f46", "1?doset") in new stack
    -- Goto (macro-dial-one,dstring,13)
    -- Executing [[email protected]:13] Set("SIP/mydivert-00000f46", "DSTRING=IAX2/329&") in new stack
    -- Executing [[email protected]:14] Set("SIP/mydivert-00000f46", "ITER=2") in new stack
    -- Executing [[email protected]:15] GotoIf("SIP/mydivert-00000f46", "0?begin") in new stack
    -- Executing [[email protected]:16] ExecIf("SIP/mydivert-00000f46", "0?Return()") in new stack
    -- Executing [[email protected]:17] Set("SIP/mydivert-00000f46", "DSTRING=IAX2/329") in new stack
    -- Executing [[email protected]:18] Return("SIP/mydivert-00000f46", "") in new stack
    -- Executing [[email protected]:27] GotoIf("SIP/mydivert-00000f46", "0?nodial") in new stack
    -- Executing [[email protected]:28] GotoIf("SIP/mydivert-00000f46", "0?skiptrace") in new stack
    -- Executing [[email protected]:29] GosubIf("SIP/mydivert-00000f46", "1?ctset,1():ctclear,1()") in new stack
    -- Executing [[email protected]:1] Set("SIP/mydivert-00000f46", "DB(CALLTRACE/329)=44203XXXXXXX") in new stack
    -- Executing [[email protected]:2] Return("SIP/mydivert-00000f46", "") in new stack
    -- Executing [[email protected]:30] Set("SIP/mydivert-00000f46", "D_OPTIONS=Ttr") in new stack
    -- Executing [[email protected]:31] ExecIf("SIP/mydivert-00000f46", "0?SIPAddHeader(Alert-Info: )") in new stack
    -- Executing [[email protected]:32] ExecIf("SIP/mydivert-00000f46", "0?SIPAddHeader()") in new stack
    -- Executing [[email protected]:33] ExecIf("SIP/mydivert-00000f46", "1?Set(CHANNEL(musicclass)=default)") in new stack
    -- Executing [[email protected]:34] GosubIf("SIP/mydivert-00000f46", "0?qwait,1()") in new stack
    -- Executing [[email protected]:35] Set("SIP/mydivert-00000f46", "__CWIGNORE=") in new stack
    -- Executing [[email protected]:36] Set("SIP/mydivert-00000f46", "__KEEPCID=TRUE") in new stack
    -- Executing [[email protected]:37] GotoIf("SIP/mydivert-00000f46", "0?usegoto,1") in new stack
    -- Executing [[email protected]:38] GotoIf("SIP/mydivert-00000f46", "1?godial") in new stack
    -- Goto (macro-dial-one,s,43)
    -- Executing [[email protected]:43] Macro("SIP/mydivert-00000f46", "dialout-one-predial-hook,") in new stack
    -- Executing [[email protected]:1] MacroExit("SIP/mydivert-00000f46", "") in new stack
    -- Executing [[email protected]:44] Dial("SIP/mydivert-00000f46", "IAX2/329,15,Ttr") in new stack
    -- Call accepted by 127.0.0.1 (format alaw)
    -- Format for call is (alaw)
    -- Called IAX2/329
    -- IAX2/329-14897 is ringing
    -- Nobody picked up in 15000 ms
    -- Hungup 'IAX2/329-14897'
    -- Executing [[email protected]:45] ExecIf("SIP/mydivert-00000f46", "0?MacroExit()") in new stack
    -- Executing [[email protected]:46] ExecIf("SIP/mydivert-00000f46", "0?Set(DIALSTATUS=)") in new stack
    -- Executing [[email protected]:47] GosubIf("SIP/mydivert-00000f46", "0?s-NOANSWER,1()") in new stack
    -- Executing [[email protected]:48] MacroExit("SIP/mydivert-00000f46", "") in new stack
    -- Executing [[email protected]:15] Set("SIP/mydivert-00000f46", "SV_DIALSTATUS=NOANSWER") in new stack
    -- Executing [[email protected]:16] GosubIf("SIP/mydivert-00000f46", "0?docfu,1()") in new stack
    -- Executing [[email protected]:17] GosubIf("SIP/mydivert-00000f46", "0?docfb,1()") in new stack
    -- Executing [[email protected]:18] Set("SIP/mydivert-00000f46", "DIALSTATUS=NOANSWER") in new stack
    -- Executing [[email protected]cro-exten-vm:19] ExecIf("SIP/mydivert-00000f46", "0?MacroExit()") in new stack
    -- Executing [[email protected]:20] GotoIf("SIP/mydivert-00000f46", "0?s-NOANSWER,1") in new stack
    -- Executing [[email protected]:21] Macro("SIP/mydivert-00000f46", "vm,329,NOANSWER,") in new stack
    -- Executing [[email protected]:1] Macro("SIP/mydivert-00000f46", "user-callerid,SKIPTTL") in new stack
    -- Executing [[email protected]:1] Set("SIP/mydivert-00000f46", "TOUCH_MONITOR=1442501225.4154") in new stack
    -- Executing [[email protected]:2] Set("SIP/mydivert-00000f46", "AMPUSER=44203XXXXXXX") in new stack
    -- Executing [[email protected]:3] GotoIf("SIP/mydivert-00000f46", "0?report") in new stack
    -- Executing [[email protected]:4] ExecIf("SIP/mydivert-00000f46", "0?Set(REALCALLERIDNUM=44203XXXXXXX)") in new stack
    -- Executing [[email protected]:5] Set("SIP/mydivert-00000f46", "AMPUSER=") in new stack
    -- Executing [[email protected]:6] GotoIf("SIP/mydivert-00000f46", "0?limit") in new stack
    -- Executing [[email protected]:7] Set("SIP/mydivert-00000f46", "AMPUSERCIDNAME=") in new stack
    -- Executing [[email protected]:8] GotoIf("SIP/mydivert-00000f46", "1?report") in new stack
    -- Goto (macro-user-callerid,s,14)
    -- Executing [[email protected]:14] GotoIf("SIP/mydivert-00000f46", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,27)
    -- Executing [[email protected]:27] Set("SIP/mydivert-00000f46", "CALLERID(number)=44203XXXXXXX") in new stack
    -- Executing [[email protected]:28] Set("SIP/mydivert-00000f46", "CALLERID(name)=44203XXXXXXX") in new stack
    -- Executing [[email protected]:29] Set("SIP/mydivert-00000f46", "CDR(cnum)=44203XXXXXXX") in new stack
    -- Executing [[email protected]:30] Set("SIP/mydivert-00000f46", "CDR(cnam)=44203XXXXXXX") in new stack
    -- Executing [[email protected]:31] Set("SIP/mydivert-00000f46", "CHANNEL(language)=en") in new stack
    -- Executing [[email protected]:2] Set("SIP/mydivert-00000f46", "VMGAIN=") in new stack
    -- Executing [[email protected]:3] Macro("SIP/mydivert-00000f46", "blkvm-check,") in new stack
    -- Executing [[email protected]:1] Set("SIP/mydivert-00000f46", "GOSUB_RETVAL=") in new stack
    -- Executing [[email protected]:2] ExecIf("SIP/mydivert-00000f46", "0?Set(GOSUB_RETVAL=TRUE)") in new stack
    -- Executing [[email protected]:3] MacroExit("SIP/mydivert-00000f46", "") in new stack
    -- Executing [[email protected]:4] GotoIf("SIP/mydivert-00000f46", "1?vmx,1") in new stack
    -- Goto (macro-vm,vmx,1)
    -- Executing [[email protected]:1] Set("SIP/mydivert-00000f46", "MEXTEN=329") in new stack
    -- Executing [[email protected]:2] Set("SIP/mydivert-00000f46", "MMODE=NOANSWER") in new stack
    -- Executing [[email protected]:3] Set("SIP/mydivert-00000f46", "RETVM=") in new stack
    -- Executing [[email protected]:4] Set("SIP/mydivert-00000f46", "MODE=unavail") in new stack
    -- Executing [[email protected]:5] Macro("SIP/mydivert-00000f46", "get-vmcontext,329") in new stack
    -- Executing [[email protected]:1] Set("SIP/mydivert-00000f46", "[email protected]") in new stack
    -- Executing [[email protected]:2] GotoIf("SIP/mydivert-00000f46", "0?200:300") in new stack
    -- Goto (macro-get-vmcontext,s,300)
    -- Executing [[email protected]:300] NoOp("SIP/mydivert-00000f46", "") in new stack
    -- Executing [[email protected]:6] Set("SIP/mydivert-00000f46", "MODE=unavail") in new stack
    -- Executing [[email protected]:7] NoOp("SIP/mydivert-00000f46", "MODE IS: unavail") in new stack
    -- Executing [[email protected]:8] GotoIf("SIP/mydivert-00000f46", "1?chknomsg") in new stack
    -- Goto (macro-vm,vmx,10)
    -- Executing [[email protected]:10] GotoIf("SIP/mydivert-00000f46", "0?s-NOANSWER,1") in new stack
    -- Executing [[email protected]:11] GotoIf("SIP/mydivert-00000f46", "1?notdirect") in new stack
    -- Goto (macro-vm,vmx,13)
    -- Executing [[email protected]:13] NoOp("SIP/mydivert-00000f46", "Checking if ext 329 is enabled: ") in new stack
    -- Executing [[email protected]:14] GotoIf("SIP/mydivert-00000f46", "1?s-NOANSWER,1") in new stack
    -- Goto (macro-vm,s-NOANSWER,1)
    -- Executing [[email protected]:1] Macro("SIP/mydivert-00000f46", "get-vmcontext,329") in new stack
    -- Executing [[email protected]:1] Set("SIP/mydivert-00000f46", "[email protected]") in new stack
    -- Executing [[email protected]:2] GotoIf("SIP/mydivert-00000f46", "0?200:300") in new stack
    -- Goto (macro-get-vmcontext,s,300)
    -- Executing [[email protected]:300] NoOp("SIP/mydivert-00000f46", "") in new stack
    -- Executing [[email protected]:2] VoiceMail("SIP/mydivert-00000f46", "[email protected]@device,u") in new stack
[2015-09-17 09:47:26] WARNING[32115][C-00000fa9]: app_voicemail.c:6379 leave_voicemail: No entry in voicemail config file for '329'
    -- Executing [[email protected]:3] Goto("SIP/mydivert-00000f46", "exit-FAILED,1") in new stack
    -- Goto (macro-vm,exit-FAILED,1)
    -- Executing [[email protected]:1] Playback("SIP/mydivert-00000f46", "im-sorry&an-error-has-occured") in new stack
    -- <SIP/mydivert-00000f46> Playing 'im-sorry.alaw' (language 'en')
    -- <SIP/mydivert-00000f46> Playing 'an-error-has-occured.alaw' (language 'en')
    -- Executing [[email protected]:2] GotoIf("SIP/mydivert-00000f46", "0?exit-RETURN,1") in new stack
    -- Executing [[email protected]:3] Hangup("SIP/mydivert-00000f46", "") in new stack
  == Spawn extension (macro-vm, exit-FAILED, 3) exited non-zero on 'SIP/mydivert-00000f46' in macro 'vm'
  == Spawn extension (macro-exten-vm, s, 21) exited non-zero on 'SIP/mydivert-00000f46' in macro 'exten-vm'
  == Spawn extension (from-did-direct, 329, 2) exited non-zero on 'SIP/mydivert-00000f46'
    -- Executing [[email protected]:1] Macro("SIP/mydivert-00000f46", "hangupcall,") in new stack
    -- Executing [[email protected]:1] ExecIf("SIP/mydivert-00000f46", "0?Set(CDR(recordingfile)=.wav)") in new stack
    -- Executing [[email protected]:2] GotoIf("SIP/mydivert-00000f46", "1?theend") in new stack
    -- Goto (macro-hangupcall,s,4)
    -- Executing [[email protected]:4] Hangup("SIP/mydivert-00000f46", "") in new stack
  == Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'SIP/mydivert-00000f46' in macro 'hangupcall'
  == Spawn extension (from-did-direct, h, 1) exited non-zero on 'SIP/mydivert-00000f46'