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=