FAXpro; seems to receive fax (statusstr=ok) but FAXSTATUS=FAILED

When I receive faxes, after the fax transmission is completed, the TIF and PDF files are created, I get the following error, and the faxes are NOT e-mailed. I can manually go to /var/spool/asterisk/fax and retrieve the documents.

[2016-03-18 15:40:52] VERBOSE[22366][C-00000563]
pbx.c: Executing [s@ext-fax:5] ExecIf(“DAHDI/2-1”, “0?Set(FAXSTATUS=“FAILED:
error: statusstr: OK”)”) in new stack

Any ideas?

Entire log for this call is available below.

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563]
sig_analog.c: Starting simple switch on ‘DAHDI/2-1’

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@from-analog:1] NoOp(“DAHDI/2-1”, "Entering
from-dahdi with DID == ") in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@from-analog:2] Ringing(“DAHDI/2-1”, “”) in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@from-analog:3] Set(“DAHDI/2-1”, “DID=s”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@from-analog:4] NoOp(“DAHDI/2-1”, “DID is now s”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@from-analog:5] GotoIf(“DAHDI/2-1”, “1?dahdiok:checkzap”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Goto (from-analog,s,9)

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@from-analog:9] NoOp(“DAHDI/2-1”, “Is a DAHDi
Channel”) in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@from-analog:10] Set(“DAHDI/2-1”, “CHAN=2-1”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@from-analog:11] Set(“DAHDI/2-1”, “CHAN=2”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@from-analog:12] Macro(“DAHDI/2-1”, “from-dahdi-2,s,1”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@macro-from-dahdi-2:1] NoOp(“DAHDI/2-1”, “Entering
macro-from-dahdi-2 with DID = s and setting to: 8083244640”) in new
stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@macro-from-dahdi-2:2] Set(“DAHDI/2-1”, “__FROM_DID=8083244640”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@macro-from-dahdi-2:3] Goto(“DAHDI/2-1”, “from-trunk,8083244640,1”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Goto (from-trunk,8083244640,1)

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563]
app_macro.c: Channel ‘DAHDI/2-1’ jumping out of macro ‘from-dahdi-2’

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [8083244640@from-trunk:1] Set(“DAHDI/2-1”, “__FROM_DID=8083244640”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [8083244640@from-trunk:2] Gosub(“DAHDI/2-1”, “sub-record-check,s,1(in,8083244640,never)”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@sub-record-check:1] GotoIf(“DAHDI/2-1”, “0?initialized”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@sub-record-check:2] Set(“DAHDI/2-1”, “__REC_STATUS=INITIALIZED”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@sub-record-check:3] Set(“DAHDI/2-1”, “NOW=1458351592”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@sub-record-check:4] Set(“DAHDI/2-1”, “__DAY=18”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@sub-record-check:5] Set(“DAHDI/2-1”, “__MONTH=03”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@sub-record-check:6] Set(“DAHDI/2-1”, “__YEAR=2016”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@sub-record-check:7] Set(“DAHDI/2-1”, “__TIMESTR=20160318-153952”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@sub-record-check:8] Set(“DAHDI/2-1”, “__FROMEXTEN=unknown”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@sub-record-check:9] Set(“DAHDI/2-1”, “__MON_FMT=wav”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@sub-record-check:10] NoOp(“DAHDI/2-1”, “Recordings
initialized”) in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@sub-record-check:11] ExecIf(“DAHDI/2-1”, “0?Set(ARG3=dontcare)”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@sub-record-check:12] Set(“DAHDI/2-1”, “REC_POLICY_MODE_SAVE=”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@sub-record-check:13] ExecIf(“DAHDI/2-1”, “0?Set(REC_STATUS=NO)”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@sub-record-check:14] GotoIf(“DAHDI/2-1”, “2?checkaction”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Goto (sub-record-check,s,17)

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@sub-record-check:17] GotoIf(“DAHDI/2-1”, “1?sub-record-check,in,1”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Goto (sub-record-check,in,1)

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [in@sub-record-check:1] NoOp(“DAHDI/2-1”, “Inbound
Recording Check to 8083244640”) in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [in@sub-record-check:2] Set(“DAHDI/2-1”, “FROMEXTEN=unknown”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [in@sub-record-check:3] ExecIf(“DAHDI/2-1”, “0?Set(FROMEXTEN=)”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [in@sub-record-check:4] Gosub(“DAHDI/2-1”, “recordcheck,1(never,in,8083244640)”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [recordcheck@sub-record-check:1] NoOp(“DAHDI/2-1”, “Starting
recording check against never”) in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [recordcheck@sub-record-check:2] Goto(“DAHDI/2-1”, “never”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Goto (sub-record-check,recordcheck,14)

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [recordcheck@sub-record-check:14] Set(“DAHDI/2-1”, “__REC_POLICY_MODE=NEVER”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [recordcheck@sub-record-check:15] Goto(“DAHDI/2-1”, “stoprec”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Goto (sub-record-check,recordcheck,25)

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [recordcheck@sub-record-check:25] NoOp(“DAHDI/2-1”, “Stopping
recording: in, 8083244640”) in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [recordcheck@sub-record-check:26] Set(“DAHDI/2-1”, “__REC_STATUS=STOPPED”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [recordcheck@sub-record-check:27] System(“DAHDI/2-1”, “/var/lib/asterisk/bin/stoprecording.php
"DAHDI/2-1"”) in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [recordcheck@sub-record-check:28] Return(“DAHDI/2-1”, “”) in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [in@sub-record-check:5] Return(“DAHDI/2-1”, “”) in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [8083244640@from-trunk:3] Gosub(“DAHDI/2-1”, “app-blacklist-check,s,1()”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@app-blacklist-check:1] GotoIf(“DAHDI/2-1”, “0?blacklisted”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@app-blacklist-check:2] Set(“DAHDI/2-1”, “CALLED_BLACKLIST=1”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@app-blacklist-check:3] Return(“DAHDI/2-1”, “”) in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [8083244640@from-trunk:4] Set(“DAHDI/2-1”, “CDR(did)=8083244640”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [8083244640@from-trunk:5] ExecIf(“DAHDI/2-1”, “1
?Set(CALLERID(name)=)”) in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [8083244640@from-trunk:6] Set(“DAHDI/2-1”, “__MOHCLASS=”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [8083244640@from-trunk:7] Ringing(“DAHDI/2-1”, “”) in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [8083244640@from-trunk:8] Set(“DAHDI/2-1”, “__REVERSAL_REJECT=FALSE”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [8083244640@from-trunk:9] GotoIf(“DAHDI/2-1”, “1?post-reverse-charge”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Goto (from-trunk,8083244640,11)

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [8083244640@from-trunk:11] NoOp(“DAHDI/2-1”, “”) in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [8083244640@from-trunk:12] Set(“DAHDI/2-1”, “__CALLINGNAMEPRES_SV=allowed_not_screened”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [8083244640@from-trunk:13] Set(“DAHDI/2-1”, “__CALLINGNUMPRES_SV=allowed_not_screened”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [8083244640@from-trunk:14] Set(“DAHDI/2-1”, “CALLERID(name-pres)=allowed_not_screened”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [8083244640@from-trunk:15] Set(“DAHDI/2-1”, “CALLERID(num-pres)=allowed_not_screened”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [8083244640@from-trunk:16] Set(“DAHDI/2-1”,
"__ALERT_INFO= ") in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [8083244640@from-trunk:17] NoOp(“DAHDI/2-1”, “CallerID Entry
Point”) in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [8083244640@from-trunk:18] Macro(“DAHDI/2-1”, “prepend-cid,Kealaola:”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@macro-prepend-cid:1] GotoIf(“DAHDI/2-1”, “1?REPCID”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Goto (macro-prepend-cid,s,5)

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@macro-prepend-cid:5] Set(“DAHDI/2-1”, “_RGPREFIX=Kealaola:”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@macro-prepend-cid:6] Set(“DAHDI/2-1”, “CALLERID(name)=Kealaola:”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [8083244640@from-trunk:19] Set(“DAHDI/2-1”, “FAX_DEST=ext-fax^29^1”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [8083244640@from-trunk:20] Set(“DAHDI/2-1”, “FAXOPT(faxdetect)=yes”)
in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [8083244640@from-trunk:21] Answer(“DAHDI/2-1”, “”) in new stack

[2016-03-18 15:39:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [8083244640@from-trunk:22] Wait(“DAHDI/2-1”, “8”)
in new stack

[2016-03-18 15:39:57] VERBOSE[22366][C-00000563]
res_fax.c: Redirecting ‘DAHDI/2-1’ to fax extension due to CNG detection

[2016-03-18 15:39:57] VERBOSE[22366][C-00000563] pbx.c:
Spawn extension (from-trunk, fax, 1) exited non-zero on ‘DAHDI/2-1’

[2016-03-18 15:39:57] VERBOSE[22366][C-00000563] pbx.c:
Executing [fax@from-trunk:1] Goto(“DAHDI/2-1”, “ext-fax,29,1”)
in new stack

[2016-03-18 15:39:57] VERBOSE[22366][C-00000563] pbx.c:
Goto (ext-fax,29,1)

[2016-03-18 15:39:57] VERBOSE[22366][C-00000563] pbx.c:
Executing [29@ext-fax:1] Set(“DAHDI/2-1”,
“FAX_FOR=Kealaola Fax (29)”) in new stack

[2016-03-18 15:39:57] VERBOSE[22366][C-00000563] pbx.c:
Executing [29@ext-fax:2] NoOp(“DAHDI/2-1”,
“Receiving Fax for: Kealaola Fax (29), From:
“Kealaola:” <>”) in new stack

[2016-03-18 15:39:57] VERBOSE[22366][C-00000563] pbx.c:
Executing [29@ext-fax:3] Set(“DAHDI/2-1”,
“FAX_ATTACH_FORMAT=pdf”) in new stack

[2016-03-18 15:39:57] VERBOSE[22366][C-00000563] pbx.c:
Executing [29@ext-fax:4] Set(“DAHDI/2-1”,
"[email protected]") in new
stack

[2016-03-18 15:39:57] VERBOSE[22366][C-00000563] pbx.c:
Executing [29@ext-fax:5] ExecIf(“DAHDI/2-1”, “1?Set(ARIUSER=29)”)
in new stack

[2016-03-18 15:39:57] VERBOSE[22366][C-00000563] pbx.c:
Executing [29@ext-fax:6] ExecIf(“DAHDI/2-1”, “1?AGI(fax.agi)”)
in new stack

[2016-03-18 15:39:57] VERBOSE[22366][C-00000563]
res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/fax.agi

[2016-03-18 15:39:57] VERBOSE[22366][C-00000563]
res_agi.c: <DAHDI/2-1>AGI Script fax.agi completed, returning 0

[2016-03-18 15:39:57] VERBOSE[22366][C-00000563] pbx.c:
Executing [29@ext-fax:7] Goto(“DAHDI/2-1”,
“s,receivefax”) in new stack

[2016-03-18 15:39:57] VERBOSE[22366][C-00000563] pbx.c:
Goto (ext-fax,s,3)

[2016-03-18 15:39:57] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@ext-fax:3] StopPlayTones(“DAHDI/2-1”, “”) in new stack

[2016-03-18 15:39:57] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@ext-fax:4] ReceiveFAX(“DAHDI/2-1”, “/var/spool/asterisk/fax/1458351592.14192.tif,f”)
in new stack

[2016-03-18 15:39:57] VERBOSE[22366][C-00000563]
res_fax.c: Channel ‘DAHDI/2-1’ receiving FAX
’/var/spool/asterisk/fax/1458351592.14192.tif’

[2016-03-18 15:40:09] WARNING[22366][C-00000563]
res_fax_spandsp.c: WARNING T.30 ECM carrier not found

[2016-03-18 15:40:09] WARNING[22366][C-00000563]
res_fax_spandsp.c: WARNING T.30 ECM carrier not found

[2016-03-18 15:40:10] WARNING[22366][C-00000563]
res_fax_spandsp.c: WARNING T.30 ECM carrier not found

[2016-03-18 15:40:10] WARNING[22366][C-00000563] res_fax_spandsp.c:
WARNING T.30 ECM carrier not found

[2016-03-18
15:40:52] VERBOSE[22366][C-00000563] pbx.c: Executing
[s@ext-fax:5] ExecIf(“DAHDI/2-1”,
“0?Set(FAXSTATUS=“FAILED: error: statusstr:
OK”)”) in new stack

[2016-03-18 15:40:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@ext-fax:6] Hangup(“DAHDI/2-1”, “”) in new stack

[2016-03-18 15:40:52] VERBOSE[22366][C-00000563] pbx.c:
Spawn extension (ext-fax, s, 6) exited non-zero on ‘DAHDI/2-1’

[2016-03-18 15:40:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [h@ext-fax:1] GotoIf(“DAHDI/2-1”, “0?failed”)
in new stack

[2016-03-18 15:40:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [h@ext-fax:2] GotoIf(“DAHDI/2-1”, “0?noemail”)
in new stack

[2016-03-18 15:40:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [h@ext-fax:3] Set(“DAHDI/2-1”,
“DELETE_AFTER_SEND=false”) in new stack

[2016-03-18 15:40:52] VERBOSE[22366][C-00000563] pbx.c:
Executing [h@ext-fax:4] System(“DAHDI/2-1”, “/var/lib/asterisk/bin/fax2mail.php
–remotestationid “8083288972 " --to "[email protected]
–dest “8083244640” --callerid ‘“Kealaola:” <>’
–file /var/spool/asterisk/fax/1458351592.14192.tif --exten “Kealaola Fax
(29)” --delete “false” --attachformat “pdf””)
in new stack

[2016-03-18 15:40:53] VERBOSE[22366][C-00000563] pbx.c:
Executing [h@ext-fax:5] ExecIf(“DAHDI/2-1”, “1?system(/var/lib/asterisk/bin/faxpro_helper.php
–action=“receive” --user=“29” --dest=“29”
–callerid=‘Kealaola%3A <>’
–file=”/var/spool/asterisk/fax/1458351592.14192.tif"
–direction=“in” --status=“OK”)") in new stack

[2016-03-18 15:40:53] VERBOSE[22366][C-00000563] pbx.c:
Executing [h@ext-fax:6] Macro(“DAHDI/2-1”,
“hangupcall,”) in new stack

[2016-03-18 15:40:53] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@macro-hangupcall:1] GotoIf(“DAHDI/2-1”, “1?theend”)
in new stack

[2016-03-18 15:40:53] VERBOSE[22366][C-00000563] pbx.c:
Goto (macro-hangupcall,s,3)

[2016-03-18 15:40:53] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@macro-hangupcall:3] ExecIf(“DAHDI/2-1”, “0?Set(CDR(recordingfile)=)”)
in new stack

[2016-03-18 15:40:53] VERBOSE[22366][C-00000563] pbx.c:
Executing [s@macro-hangupcall:4] Hangup(“DAHDI/2-1”, “”) in new stack

[2016-03-18 15:40:53] VERBOSE[22366][C-00000563]
app_macro.c: Spawn extension (macro-hangupcall, s, 4) exited non-zero on
’DAHDI/2-1’ in macro ‘hangupcall’

[2016-03-18 15:40:53] VERBOSE[22366][C-00000563] pbx.c:
Spawn extension (ext-fax, h, 6) exited non-zero on ‘DAHDI/2-1’

[2016-03-18 15:40:53] VERBOSE[22366][C-00000563]
sig_analog.c: Hanging up on ‘DAHDI/2-1’

[2016-03-18 15:40:53] VERBOSE[22366][C-00000563]
chan_dahdi.c: Hungup ‘DAHDI/2-1’

Something with your setup is causing asterisk to state the faxes are failed. Also inbound faxing has nothing to do with Fax Pro. Fax Pro provides outbound faxing.

What version of FreePBX and Fax do you have installed?

Thanks for the response.

I’m running:
FreePBX 13.0.79
Fax Configuration 13.0.26
(Fax Configuration Professional 13.0.27)

Thanks for the response.

I’m running:
FreePBX 13.0.79
Fax Configuration 13.0.26
(Fax Configuration Professional 13.0.27)