System Fax <666> apparently not working anymore

Dear all: I’ve been using System Fax since installing FreePBX back in 2014. Fax services are only used on a particular time of the year, between October and April. Last time I used it, and it worked, was on May 2015.

Fast forward to today, and it seems the fax is never sent to the email destination configured on Fax Configuration under Settings tab, even though 666 feature code still works, TIF file gets generated and variable FAX_RX_EMAIL gets correctly populated.

I searched all along and the only reference that I could find was from Tony Lewis on this post Inbound Fax to Email not working after updates where he states that System Fax should not be used anymore.

Is there a way we can have System Fax re-enabled? I find it very useful, as it was used for a central fax location without the need to create a specific fax destination or configuring inbound fax for a particular user.

FreePBX Distro Version: 10.13.66-16
Fax Module Version: 13.0.39.2

Below is the log for the attempted incoming fax, where it can be seen that the destination mail as configured in Fax Module is correctly set into variable FAX_RX_EMAIL (obscured for anti-spam reasons).

[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:1] Set(“SIP/106-000005c2”, "[email protected]") in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:2] Goto(“SIP/106-000005c2”, “ext-fax,s,1”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Goto (ext-fax,s,1)
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:1] Macro(“SIP/106-000005c2”, “user-callerid,”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:1] Set(“SIP/106-000005c2”, “TOUCH_MONITOR=1478626910.1695”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:2] Set(“SIP/106-000005c2”, “AMPUSER=106”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:3] GotoIf(“SIP/106-000005c2”, “0?report”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:4] ExecIf(“SIP/106-000005c2”, “1?Set(REALCALLERIDNUM=106)”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:5] Set(“SIP/106-000005c2”, “AMPUSER=106”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:6] GotoIf(“SIP/106-000005c2”, “0?limit”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:7] Set(“SIP/106-000005c2”, “AMPUSERCIDNAME=Soledad Taboada”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:8] GotoIf(“SIP/106-000005c2”, “0?report”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:9] Set(“SIP/106-000005c2”, “AMPUSERCID=106”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:10] Set(“SIP/106-000005c2”, “__DIAL_OPTIONS=Ttr”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:11] Set(“SIP/106-000005c2”, “CALLERID(all)=“Soledad Taboada” <106>”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:12] GotoIf(“SIP/106-000005c2”, “0?limit”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:13] ExecIf(“SIP/106-000005c2”, “0?Set(GROUP(concurrency_limit)=106)”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:14] GosubIf(“SIP/106-000005c2”, “7?sub-ccss,s,1(ext-fax,666)”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:1] ExecIf(“SIP/106-000005c2”, “0?Return()”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:2] Set(“SIP/106-000005c2”, “CCSS_SETUP=TRUE”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:3] GosubIf(“SIP/106-000005c2”, “0?monitor_config,1(ext-fax,666):monitor_default,1(ext-fax,666)”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:1] GotoIf(“SIP/106-000005c2”, “0?is_exten”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:2] StackPop(“SIP/106-000005c2”, “”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:3] Return(“SIP/106-000005c2”, “FALSE”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:15] ExecIf(“SIP/106-000005c2”, “0?Set(CHANNEL(language)=)”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:16] GotoIf(“SIP/106-000005c2”, “0?continue”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:17] ExecIf(“SIP/106-000005c2”, “1?Set(__CALLEE_ACCOUNCODE=)”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:18] Set(“SIP/106-000005c2”, “__TTL=64”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:19] GotoIf(“SIP/106-000005c2”, “1?continue”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Goto (macro-user-callerid,s,30)
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:30] Set(“SIP/106-000005c2”, “CALLERID(number)=106”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:31] Set(“SIP/106-000005c2”, “CALLERID(name)=Soledad Taboada”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:32] GotoIf(“SIP/106-000005c2”, “0?cnum”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:33] Set(“SIP/106-000005c2”, “CDR(cnam)=Soledad Taboada”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:34] Set(“SIP/106-000005c2”, “CDR(cnum)=106”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:35] Set(“SIP/106-000005c2”, “CHANNEL(language)=es”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:2] NoOp(“SIP/106-000005c2”, “Receiving Fax for: , From: “Soledad Taboada” <106>”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:3] StopPlayTones(“SIP/106-000005c2”, “”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:4] ReceiveFAX(“SIP/106-000005c2”, “/var/spool/asterisk/fax/1478626910.1695.tif,f”) in new stack
[2016-11-08 14:41:50] VERBOSE[6016][C-000003c3] res_fax.c: – Channel ‘SIP/106-000005c2’ receiving FAX ‘/var/spool/asterisk/fax/1478626910.1695.tif’
[2016-11-08 14:41:54] VERBOSE[2259][C-000003c2] res_musiconhold.c: – Stopped music on hold on DAHDI/1-1
[2016-11-08 14:41:54] DEBUG[2259][C-000003c2] chan_dahdi.c: New owner for channel 1 is DAHDI/1-1 (owner transfer 0xb7202034 -> 0x9604214)
[2016-11-08 14:41:54] VERBOSE[5965][C-000003c2] pbx.c: – Executing [[email protected]:1] Macro(“SIP/106-000005c2”, “hangupcall,”) in new stack
[2016-11-08 14:41:54] VERBOSE[5965][C-000003c2] pbx.c: – Executing [[email protected]:1] ExecIf(“SIP/106-000005c2”, “0?Set(CDR(recordingfile)=.wav)”) in new stack
[2016-11-08 14:41:54] VERBOSE[5965][C-000003c2] pbx.c: – Executing [[email protected]:2] GotoIf(“SIP/106-000005c2”, “1?theend”) in new stack
[2016-11-08 14:41:54] VERBOSE[5965][C-000003c2] pbx.c: – Goto (macro-hangupcall,s,4)
[2016-11-08 14:41:54] VERBOSE[5965][C-000003c2] pbx.c: – Executing [[email protected]:4] ExecIf(“SIP/106-000005c2”, “0?Set(CDR(recordingfile)=)”) in new stack
[2016-11-08 14:41:54] VERBOSE[5965][C-000003c2] pbx.c: – Executing [[email protected]:5] Hangup(“SIP/106-000005c2”, “”) in new stack
[2016-11-08 14:41:54] VERBOSE[5965][C-000003c2] app_macro.c: == Spawn extension (macro-hangupcall, s, 5) exited non-zero on ‘SIP/106-000005c2’ in macro ‘hangupcall’
[2016-11-08 14:41:54] VERBOSE[5965][C-000003c2] pbx.c: == Spawn extension (macro-dial-one, h, 1) exited non-zero on ‘SIP/106-000005c2’
[2016-11-08 14:41:54] VERBOSE[5965][C-000003c2] app_macro.c: == Spawn extension (macro-dial-one, s, 51) exited non-zero on ‘SIP/106-000005c2’ in macro ‘dial-one’
[2016-11-08 14:41:54] VERBOSE[5965][C-000003c2] app_macro.c: == Spawn extension (macro-exten-vm, s, 14) exited non-zero on ‘SIP/106-000005c2’ in macro ‘exten-vm’
[2016-11-08 14:41:54] VERBOSE[5965][C-000003c2] pbx.c: == Spawn extension (from-did-direct, 106, 2) exited non-zero on ‘SIP/106-000005c2’
[2016-11-08 14:41:54] VERBOSE[2249] chan_sip.c: == Extension Changed 106[ext-local] new state Idle for Notify User 103
[2016-11-08 14:41:54] VERBOSE[2249] chan_sip.c: == Extension Changed 106[ext-local] new state Idle for Notify User 105
[2016-11-08 14:41:54] VERBOSE[2249] chan_sip.c: == Extension Changed 106[ext-local] new state Idle for Notify User 100
[2016-11-08 14:41:54] VERBOSE[2249] chan_sip.c: == Extension Changed 106[ext-local] new state Idle for Notify User 104
[2016-11-08 14:42:14] WARNING[6016][C-000003c3] res_fax_spandsp.c: WARNING T.30 Non-ECM carrier not found
[2016-11-08 14:43:05] WARNING[6016][C-000003c3] res_fax_spandsp.c: WARNING T.30 Non-ECM carrier not found
[2016-11-08 14:43:35] WARNING[6016][C-000003c3] res_fax_spandsp.c: WARNING T.30 Non-ECM carrier not found
[2016-11-08 14:44:02] WARNING[6016][C-000003c3] res_fax_spandsp.c: WARNING T.30 Non-ECM carrier not found
[2016-11-08 14:44:29] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:5] ExecIf(“DAHDI/1-1”, “0?Set(FAXSTATUS=“FAILED: error: statusstr: OK”)”) in new stack
[2016-11-08 14:44:29] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:6] Hangup(“DAHDI/1-1”, “”) in new stack
[2016-11-08 14:44:29] VERBOSE[6016][C-000003c3] pbx.c: == Spawn extension (ext-fax, s, 6) exited non-zero on ‘DAHDI/1-1’
[2016-11-08 14:44:29] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:1] GotoIf(“DAHDI/1-1”, “0?failed”) in new stack
[2016-11-08 14:44:29] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:2] Set(“DAHDI/1-1”, “DELETE_AFTER_SEND=true”) in new stack
[2016-11-08 14:44:29] WARNING[6016][C-000003c3] ast_expr2.fl: ast_yyerror(): syntax error: syntax error, unexpected ‘=’, expecting $end; Input:
= 0
^
[2016-11-08 14:44:29] WARNING[6016][C-000003c3] ast_expr2.fl: If you have questions, please refer to https://wiki.asterisk.org/wiki/display/AST/Channel+Variables
[2016-11-08 14:44:29] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:3] GotoIf(“DAHDI/1-1”, “?noemail”) in new stack
[2016-11-08 14:44:29] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:4] System(“DAHDI/1-1”, “/var/lib/asterisk/bin/fax2mail.php --remotestationid “351 4261584” --user “” --dest “4825020” --callerid “IiIgPD4=” --file /var/spool/asterisk/fax/1478626910.1695.tif --exten “” --delete “true” --attachformat “””) in new stack
[2016-11-08 14:44:30] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:5] Macro(“DAHDI/1-1”, “hangupcall,”) in new stack
[2016-11-08 14:44:30] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:1] ExecIf(“DAHDI/1-1”, “0?Set(CDR(recordingfile)=.wav)”) in new stack
[2016-11-08 14:44:30] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:2] GotoIf(“DAHDI/1-1”, “1?theend”) in new stack
[2016-11-08 14:44:30] VERBOSE[6016][C-000003c3] pbx.c: – Goto (macro-hangupcall,s,4)
[2016-11-08 14:44:30] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:4] ExecIf(“DAHDI/1-1”, “0?Set(CDR(recordingfile)=)”) in new stack
[2016-11-08 14:44:30] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:5] Hangup(“DAHDI/1-1”, “”) in new stack
[2016-11-08 14:44:30] VERBOSE[6016][C-000003c3] app_macro.c: == Spawn extension (macro-hangupcall, s, 5) exited non-zero on ‘DAHDI/1-1’ in macro ‘hangupcall’
[2016-11-08 14:44:30] VERBOSE[6016][C-000003c3] pbx.c: == Spawn extension (ext-fax, h, 5) exited non-zero on ‘DAHDI/1-1’
[2016-11-08 14:44:30] VERBOSE[6016][C-000003c3] sig_analog.c: – Hanging up on ‘DAHDI/1-1’
[2016-11-08 14:44:30] VERBOSE[6016][C-000003c3] chan_dahdi.c: – Hungup ‘DAHDI/1-1’

It is obvious that the mail2fax.php script is not doing anything because the “user” part is empty and this is the output of the script:
/var/lib/asterisk/bin/fax2mail.php --remotestationid “351 4261584” --user “” --dest “4825020” --callerid “IiIgPD4=” --file /var/spool/asterisk/fax/1478626910.1695.tif --exten “” --delete “true” --attachformat
email-fax dying, no destination found (User has no email!) and we arent keeping the file!

Also there is the error related to syntax error:
[2016-11-08 14:44:29] VERBOSE[6016][C-000003c3] pbx.c: – Executing [[email protected]:2] Set(“DAHDI/1-1”, “DELETE_AFTER_SEND=true”) in new stack
[2016-11-08 14:44:29] WARNING[6016][C-000003c3] ast_expr2.fl: ast_yyerror(): syntax error: syntax error, unexpected ‘=’, expecting $end; Input:
= 0
^
[2016-11-08 14:44:29] WARNING[6016][C-000003c3] ast_expr2.fl: If you have questions, please refer to https://wiki.asterisk.org/wiki/display/AST/Channel+Variables

I guess that an additional verification could be added so if the user is empty, and the fax is being received by System Fax 666, the variable FAX_RX_EMAIL should be used instead. I could do this myself, but manually modifying the script would break the signature and it would be lost on next module update anyway. Should I file a bug for this new behaviour?