Incoming Faxes Not Emailing Users

FreePBX (distro) v 14.0.1.36
Asterisk v 13.19.1

I’m trying to get inbound fax to email working. I was pretty sure I had it setup on our FreePBX v 13 server, but I’m thinking I might be missing something in the config now. I checked the Fax Pro-Admin wiki, and it mentioned a “Fax email” parameter that users could set in UCP, but I don’t see that in our system.

We are using AD for our user authentication, and the email address is showing for users. Here’s a log sample of me sending a test fax to myself today. I can see the fax in the file system (pdf & tiff files), and it is available in the UCP, but I did not get an email.

[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [+1251xxxxxxx@from-pstn-e164-us:1] Set("PJSIP/CenturyLink-00000db1", "CALLERID(number)=6132484818") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [+1251xxxxxxx@from-pstn-e164-us:2] Goto("PJSIP/CenturyLink-00000db1", "from-pstn,251xxxxxxx,1") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx_builtins.c: Goto (from-pstn,251xxxxxxx,1)
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [251xxxxxxx@from-pstn:1] Set("PJSIP/CenturyLink-00000db1", "__DIRECTION=INBOUND") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [251xxxxxxx@from-pstn:2] Gosub("PJSIP/CenturyLink-00000db1", "sub-record-check,s,1(in,251xxxxxxx,dontcare)") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@sub-record-check:1] GotoIf("PJSIP/CenturyLink-00000db1", "0?initialized") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@sub-record-check:2] Set("PJSIP/CenturyLink-00000db1", "__REC_STATUS=INITIALIZED") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@sub-record-check:3] Set("PJSIP/CenturyLink-00000db1", "NOW=1520273927") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@sub-record-check:4] Set("PJSIP/CenturyLink-00000db1", "__DAY=05") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@sub-record-check:5] Set("PJSIP/CenturyLink-00000db1", "__MONTH=03") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@sub-record-check:6] Set("PJSIP/CenturyLink-00000db1", "__YEAR=2018") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@sub-record-check:7] Set("PJSIP/CenturyLink-00000db1", "__TIMESTR=20180305-121847") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@sub-record-check:8] Set("PJSIP/CenturyLink-00000db1", "__FROMEXTEN=unknown") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@sub-record-check:9] Set("PJSIP/CenturyLink-00000db1", "__MON_FMT=wav") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@sub-record-check:10] NoOp("PJSIP/CenturyLink-00000db1", "Recordings initialized") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@sub-record-check:11] ExecIf("PJSIP/CenturyLink-00000db1", "0?Set(ARG3=dontcare)") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@sub-record-check:12] Set("PJSIP/CenturyLink-00000db1", "REC_POLICY_MODE_SAVE=") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@sub-record-check:13] ExecIf("PJSIP/CenturyLink-00000db1", "0?Set(REC_STATUS=NO)") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@sub-record-check:14] GotoIf("PJSIP/CenturyLink-00000db1", "2?checkaction") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx_builtins.c: Goto (sub-record-check,s,17)
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@sub-record-check:17] GotoIf("PJSIP/CenturyLink-00000db1", "1?sub-record-check,in,1") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx_builtins.c: Goto (sub-record-check,in,1)
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [in@sub-record-check:1] NoOp("PJSIP/CenturyLink-00000db1", "Inbound Recording Check to 251xxxxxxx") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [in@sub-record-check:2] Set("PJSIP/CenturyLink-00000db1", "FROMEXTEN=unknown") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [in@sub-record-check:3] ExecIf("PJSIP/CenturyLink-00000db1", "10?Set(FROMEXTEN=6132484818)") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [in@sub-record-check:4] Gosub("PJSIP/CenturyLink-00000db1", "recordcheck,1(dontcare,in,251xxxxxxx)") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp("PJSIP/CenturyLink-00000db1", "Starting recording check against dontcare") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [recordcheck@sub-record-check:2] Goto("PJSIP/CenturyLink-00000db1", "dontcare") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [recordcheck@sub-record-check:3] Return("PJSIP/CenturyLink-00000db1", "") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [in@sub-record-check:5] Return("PJSIP/CenturyLink-00000db1", "") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [251xxxxxxx@from-pstn:3] Gosub("PJSIP/CenturyLink-00000db1", "app-blacklist-check,s,1()") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@app-blacklist-check:1] GotoIf("PJSIP/CenturyLink-00000db1", "0?blacklisted") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@app-blacklist-check:2] Set("PJSIP/CenturyLink-00000db1", "CALLED_BLACKLIST=1") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@app-blacklist-check:3] Return("PJSIP/CenturyLink-00000db1", "") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [251xxxxxxx@from-pstn:4] Set("PJSIP/CenturyLink-00000db1", "__FROM_DID=251xxxxxxx") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [251xxxxxxx@from-pstn:5] Set("PJSIP/CenturyLink-00000db1", "CDR(did)=251xxxxxxx") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [251xxxxxxx@from-pstn:6] ExecIf("PJSIP/CenturyLink-00000db1", "0 ?Set(CALLERID(name)=6132484818)") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [251xxxxxxx@from-pstn:7] Set("PJSIP/CenturyLink-00000db1", "__MOHCLASS=") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [251xxxxxxx@from-pstn:8] Set("PJSIP/CenturyLink-00000db1", "__REVERSAL_REJECT=FALSE") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [251xxxxxxx@from-pstn:9] GotoIf("PJSIP/CenturyLink-00000db1", "1?post-reverse-charge") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx_builtins.c: Goto (from-pstn,251xxxxxxx,11)
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [251xxxxxxx@from-pstn:11] NoOp("PJSIP/CenturyLink-00000db1", "") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [251xxxxxxx@from-pstn:12] Set("PJSIP/CenturyLink-00000db1", "__CALLINGNAMEPRES_SV=allowed_not_screened") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [251xxxxxxx@from-pstn:13] Set("PJSIP/CenturyLink-00000db1", "__CALLINGNUMPRES_SV=allowed_not_screened") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [251xxxxxxx@from-pstn:14] Set("PJSIP/CenturyLink-00000db1", "CALLERID(name-pres)=allowed_not_screened") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [251xxxxxxx@from-pstn:15] Set("PJSIP/CenturyLink-00000db1", "CALLERID(num-pres)=allowed_not_screened") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [251xxxxxxx@from-pstn:16] NoOp("PJSIP/CenturyLink-00000db1", "CallerID Entry Point") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [251xxxxxxx@from-pstn:17] Set("PJSIP/CenturyLink-00000db1", "__CRM_DIRECTION=INBOUND") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [251xxxxxxx@from-pstn:18] Set("PJSIP/CenturyLink-00000db1", "__CRM_SOURCE=6132484818") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [251xxxxxxx@from-pstn:19] Set("PJSIP/CenturyLink-00000db1", "__CRM_LINKEDID=1520273927.3687") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [251xxxxxxx@from-pstn:20] ExecIf("PJSIP/CenturyLink-00000db1", "1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [251xxxxxxx@from-pstn:21] Goto("PJSIP/CenturyLink-00000db1", "ext-fax,11,1") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx_builtins.c: Goto (ext-fax,11,1)
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [11@ext-fax:1] Set("PJSIP/CenturyLink-00000db1", "FAX_FOR=Brad May (11)") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [11@ext-fax:2] NoOp("PJSIP/CenturyLink-00000db1", "Receiving Fax for: Brad May (11), From: "OTTAWA ON" <6132484818>") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [11@ext-fax:3] Set("PJSIP/CenturyLink-00000db1", "FAX_RX_USER=11") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [11@ext-fax:4] Set("PJSIP/CenturyLink-00000db1", "FAX_RX_EMAIL_LEN=14") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [11@ext-fax:5] ExecIf("PJSIP/CenturyLink-00000db1", "1?Set(ARIUSER=11)") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [11@ext-fax:6] ExecIf("PJSIP/CenturyLink-00000db1", "1?AGI(fax.agi)") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/fax.agi
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] res_agi.c: <PJSIP/CenturyLink-00000db1>AGI Script fax.agi completed, returning 0
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [11@ext-fax:7] Goto("PJSIP/CenturyLink-00000db1", "s,receivefax") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx_builtins.c: Goto (ext-fax,s,3)
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@ext-fax:3] StopPlayTones("PJSIP/CenturyLink-00000db1", "") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@ext-fax:4] ReceiveFAX("PJSIP/CenturyLink-00000db1", "/var/spool/asterisk/fax/1520273927.3687.tif,f") in new stack
[2018-03-05 12:18:47] VERBOSE[11815][C-000006e7] res_fax.c: Channel 'PJSIP/CenturyLink-00000db1' receiving FAX '/var/spool/asterisk/fax/1520273927.3687.tif'
[2018-03-05 12:19:00] WARNING[11815][C-000006e7] res_fax_spandsp.c: WARNING T.30 Non-ECM carrier not found
[2018-03-05 12:19:22] WARNING[11815][C-000006e7] res_fax_spandsp.c: WARNING T.30 Non-ECM carrier not found
[2018-03-05 12:19:27] WARNING[11815][C-000006e7] res_fax_spandsp.c: WARNING T.30 Page did not end cleanly
[2018-03-05 12:19:31] VERBOSE[11815][C-000006e7] pbx.c: Spawn extension (ext-fax, s, 4) exited non-zero on 'PJSIP/CenturyLink-00000db1'
[2018-03-05 12:19:31] VERBOSE[11815][C-000006e7] pbx.c: Executing [h@ext-fax:1] GotoIf("PJSIP/CenturyLink-00000db1", "0?failed") in new stack
[2018-03-05 12:19:31] VERBOSE[11815][C-000006e7] pbx.c: Executing [h@ext-fax:2] Set("PJSIP/CenturyLink-00000db1", "DELETE_AFTER_SEND=false") in new stack
[2018-03-05 12:19:31] VERBOSE[11815][C-000006e7] pbx.c: Executing [h@ext-fax:3] GotoIf("PJSIP/CenturyLink-00000db1", "0?noemail") in new stack
[2018-03-05 12:19:31] VERBOSE[11815][C-000006e7] pbx.c: Executing [h@ext-fax:4] System("PJSIP/CenturyLink-00000db1", "/var/lib/asterisk/bin/fax2mail.php --remotestationid "FAX" --user "11" --dest "251xxxxxxx" --callerid "Ik9UVEFXQSAgICAgICBPTiIgPDYxMzI0ODQ4MTg+" --file /var/spool/asterisk/fax/1520273927.3687.tif --delete "false"") in new stack
[2018-03-05 12:19:32] VERBOSE[11815][C-000006e7] pbx.c: Executing [h@ext-fax:5] ExecIf("PJSIP/CenturyLink-00000db1", "1?system(/var/lib/asterisk/bin/faxpro_helper.php --action="receive" --user="11" --dest="251xxxxxxx" --callerid="Ik9UVEFXQSAgICAgICBPTiIgPDYxMzI0ODQ4MTg+" --file="/var/spool/asterisk/fax/1520273927.3687.tif" --direction="in" --status="OK")") in new stack
[2018-03-05 12:19:32] VERBOSE[11815][C-000006e7] pbx.c: Executing [h@ext-fax:6] Macro("PJSIP/CenturyLink-00000db1", "hangupcall,") in new stack
[2018-03-05 12:19:32] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@macro-hangupcall:1] GotoIf("PJSIP/CenturyLink-00000db1", "1?theend") in new stack
[2018-03-05 12:19:32] VERBOSE[11815][C-000006e7] pbx_builtins.c: Goto (macro-hangupcall,s,3)
[2018-03-05 12:19:32] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@macro-hangupcall:3] ExecIf("PJSIP/CenturyLink-00000db1", "0?Set(CDR(recordingfile)=)") in new stack
[2018-03-05 12:19:32] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@macro-hangupcall:4] NoOp("PJSIP/CenturyLink-00000db1", " monior file= ") in new stack
[2018-03-05 12:19:32] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@macro-hangupcall:5] AGI("PJSIP/CenturyLink-00000db1", "attendedtransfer-rec-restart.php,,") in new stack
[2018-03-05 12:19:32] VERBOSE[11815][C-000006e7] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/attendedtransfer-rec-restart.php
[2018-03-05 12:19:32] VERBOSE[11815][C-000006e7] res_agi.c: <PJSIP/CenturyLink-00000db1>AGI Script attendedtransfer-rec-restart.php completed, returning 0
[2018-03-05 12:19:32] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@macro-hangupcall:6] Hangup("PJSIP/CenturyLink-00000db1", "") in new stack
[2018-03-05 12:19:32] VERBOSE[11815][C-000006e7] app_macro.c: Spawn extension (macro-hangupcall, s, 6) exited non-zero on 'PJSIP/CenturyLink-00000db1' in macro 'hangupcall'
[2018-03-05 12:19:32] VERBOSE[11815][C-000006e7] pbx.c: Spawn extension (ext-fax, h, 6) exited non-zero on 'PJSIP/CenturyLink-00000db1'
[2018-03-05 12:19:32] VERBOSE[11815][C-000006e7] app_stack.c: PJSIP/CenturyLink-00000db1 Internal Gosub(crm-hangup,s,1) start
[2018-03-05 12:19:32] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@crm-hangup:1] NoOp("PJSIP/CenturyLink-00000db1", "Sending Hangup to CRM") in new stack
[2018-03-05 12:19:32] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@crm-hangup:2] NoOp("PJSIP/CenturyLink-00000db1", "HANGUP CAUSE: 16") in new stack
[2018-03-05 12:19:32] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@crm-hangup:3] ExecIf("PJSIP/CenturyLink-00000db1", "0?Set(__CRM_VOICEMAIL=)") in new stack
[2018-03-05 12:19:32] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@crm-hangup:4] NoOp("PJSIP/CenturyLink-00000db1", "MASTER CHANNEL: 1520273927.3687 = 1520273927.3687") in new stack
[2018-03-05 12:19:32] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@crm-hangup:5] GotoIf("PJSIP/CenturyLink-00000db1", "0?return") in new stack
[2018-03-05 12:19:32] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@crm-hangup:6] Set("PJSIP/CenturyLink-00000db1", "__CRM_HANGUP=1") in new stack
[2018-03-05 12:19:32] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@crm-hangup:7] AGI("PJSIP/CenturyLink-00000db1", "sangomacrm.agi") in new stack
[2018-03-05 12:19:32] VERBOSE[11815][C-000006e7] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/sangomacrm.agi
[2018-03-05 12:19:32] VERBOSE[11815][C-000006e7] res_agi.c: <PJSIP/CenturyLink-00000db1>AGI Script sangomacrm.agi completed, returning 0
[2018-03-05 12:19:32] VERBOSE[11815][C-000006e7] pbx.c: Executing [s@crm-hangup:8] Return("PJSIP/CenturyLink-00000db1", "") in new stack
[2018-03-05 12:19:32] VERBOSE[11815][C-000006e7] app_stack.c: Spawn extension (ext-fax, h, 6) exited non-zero on 'PJSIP/CenturyLink-00000db1'
[2018-03-05 12:19:32] VERBOSE[11815][C-000006e7] app_stack.c: PJSIP/CenturyLink-00000db1 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=

Looks like the PBX side of this is working.

Look in the /var/log/maillog for more information on why the mail failed. If it didn’t get to the mail log, the fax2email.php program might have broken.

Thanks. It did end up being part of my Email settings in System Admin Pro. I didn’t have “My Hostname” and “My Origin” set correctly, but now it is working. Thanks for the info on where those logs were. That’s what put me on the path to correcting things.

This topic was automatically closed 7 days after the last reply. New replies are no longer allowed.