Fax Pro - Failed inbound faxes from only a few senders

I have recently installed Fax Pro it works to send faxes but has been failing to receive faxes from several services we need to get faxes from…here is a log of a failure…The log does not seem tell why it failed only that it failed after permitted retries. I had retires set to 1 then changed it to 3 both settings still fails… Hopefully someone can make a recommendation on what to try to get this working.

[2017-08-31 11:55:57] VERBOSE[32234][C-00000a23] pbx.c: Executing [[email protected]:105] Macro("SIP/voipms_ny6-0000093e", "hangupcall,") in new stack
[2017-08-31 11:55:57] VERBOSE[32234][C-00000a23] pbx.c: Spawn extension (ext-fax, h, 105) exited non-zero on 'SIP/voipms_ny6-0000093e'
[2017-08-31 11:56:17] VERBOSE[32469][C-00000a24] pbx.c: Executing [[email protected]:20] Goto("SIP/voipms_ny6-0000093f", "ext-fax,7,1") in new stack
[2017-08-31 11:56:17] VERBOSE[32469][C-00000a24] pbx_builtins.c: Goto (ext-fax,7,1)
[2017-08-31 11:56:17] VERBOSE[32469][C-00000a24] pbx.c: Executing [[email protected]:1] Set("SIP/voipms_ny6-0000093f", "FAX_FOR=FAX (7)") in new stack
[2017-08-31 11:56:17] VERBOSE[32469][C-00000a24] pbx.c: Executing [[email protected]:2] NoOp("SIP/voipms_ny6-0000093f", "Receiving Fax for: FAX (7), From: "9493724369" <9493724369>") in new stack
[2017-08-31 11:56:17] VERBOSE[32469][C-00000a24] pbx.c: Executing [[email protected]:3] Set("SIP/voipms_ny6-0000093f", "FAX_RX_USER=7") in new stack
[2017-08-31 11:56:17] VERBOSE[32469][C-00000a24] pbx.c: Executing [[email protected]:4] Set("SIP/voipms_ny6-0000093f", "FAX_RX_EMAIL_LEN=23") in new stack
[2017-08-31 11:56:17] VERBOSE[32469][C-00000a24] pbx.c: Executing [[email protected]:5] ExecIf("SIP/voipms_ny6-0000093f", "1?Set(ARIUSER=7)") in new stack
[2017-08-31 11:56:17] VERBOSE[32469][C-00000a24] pbx.c: Executing [[email protected]:6] ExecIf("SIP/voipms_ny6-0000093f", "1?AGI(fax.agi)") in new stack
[2017-08-31 11:56:17] VERBOSE[32469][C-00000a24] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/fax.agi
[2017-08-31 11:56:17] VERBOSE[32469][C-00000a24] res_agi.c: <SIP/voipms_ny6-0000093f>AGI Script fax.agi completed, returning 0
[2017-08-31 11:56:17] VERBOSE[32469][C-00000a24] pbx.c: Executing [[email protected]:7] Goto("SIP/voipms_ny6-0000093f", "s,receivefax") in new stack
[2017-08-31 11:56:17] VERBOSE[32469][C-00000a24] pbx_builtins.c: Goto (ext-fax,s,3)
[2017-08-31 11:56:17] VERBOSE[32469][C-00000a24] pbx.c: Executing [[email protected]:3] StopPlayTones("SIP/voipms_ny6-0000093f", "") in new stack
[2017-08-31 11:56:17] VERBOSE[32469][C-00000a24] pbx.c: Executing [[email protected]:4] ReceiveFAX("SIP/voipms_ny6-0000093f", "/var/spool/asterisk/fax/1504194974.5318.tif,f") in new stack
[2017-08-31 11:56:17] VERBOSE[32469][C-00000a24] res_fax.c: Channel 'SIP/voipms_ny6-0000093f' receiving FAX '/var/spool/asterisk/fax/1504194974.5318.tif'
[2017-08-31 11:56:39] VERBOSE[32469][C-00000a24] pbx.c: Executing [[email protected]:5] ExecIf("SIP/voipms_ny6-0000093f", "1?Set(FAXSTATUS="FAILED: error: Disconnected after permitted retries statusstr: Disconnected after permitted retries")") in new stack

Retries set to 3:

[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:1] Set("SIP/voipms_ny6-00000949", "__DIRECTION=INBOUND") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:2] Gosub("SIP/voipms_ny6-00000949", "sub-record-check,s,1(in,5084737699,dontcare)") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:1] GotoIf("SIP/voipms_ny6-00000949", "0?initialized") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:2] Set("SIP/voipms_ny6-00000949", "__REC_STATUS=INITIALIZED") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:3] Set("SIP/voipms_ny6-00000949", "NOW=1504197080") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:4] Set("SIP/voipms_ny6-00000949", "__DAY=31") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:5] Set("SIP/voipms_ny6-00000949", "__MONTH=08") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:6] Set("SIP/voipms_ny6-00000949", "__YEAR=2017") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:7] Set("SIP/voipms_ny6-00000949", "__TIMESTR=20170831-123120") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:8] Set("SIP/voipms_ny6-00000949", "__FROMEXTEN=unknown") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:9] Set("SIP/voipms_ny6-00000949", "__MON_FMT=wav") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:10] NoOp("SIP/voipms_ny6-00000949", "Recordings initialized") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:11] ExecIf("SIP/voipms_ny6-00000949", "0?Set(ARG3=dontcare)") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:12] Set("SIP/voipms_ny6-00000949", "REC_POLICY_MODE_SAVE=") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:13] ExecIf("SIP/voipms_ny6-00000949", "0?Set(REC_STATUS=NO)") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:14] GotoIf("SIP/voipms_ny6-00000949", "2?checkaction") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx_builtins.c: Goto (sub-record-check,s,17)
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:17] GotoIf("SIP/voipms_ny6-00000949", "1?sub-record-check,in,1") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx_builtins.c: Goto (sub-record-check,in,1)
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:1] NoOp("SIP/voipms_ny6-00000949", "Inbound Recording Check to 5084737699") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:2] Set("SIP/voipms_ny6-00000949", "FROMEXTEN=unknown") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:3] ExecIf("SIP/voipms_ny6-00000949", "10?Set(FROMEXTEN=4029703226)") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:4] Gosub("SIP/voipms_ny6-00000949", "recordcheck,1(dontcare,in,5084737699)") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:1] NoOp("SIP/voipms_ny6-00000949", "Starting recording check against dontcare") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:2] Goto("SIP/voipms_ny6-00000949", "dontcare") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:3] Return("SIP/voipms_ny6-00000949", "") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:5] Return("SIP/voipms_ny6-00000949", "") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:3] Gosub("SIP/voipms_ny6-00000949", "app-blacklist-check,s,1()") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:1] GotoIf("SIP/voipms_ny6-00000949", "0?blacklisted") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:2] Set("SIP/voipms_ny6-00000949", "CALLED_BLACKLIST=1") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:3] Return("SIP/voipms_ny6-00000949", "") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:4] Set("SIP/voipms_ny6-00000949", "__FROM_DID=5084737699") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:5] Set("SIP/voipms_ny6-00000949", "CDR(did)=5084737699") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:6] ExecIf("SIP/voipms_ny6-00000949", "0 ?Set(CALLERID(name)=4029703226)") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:7] Set("SIP/voipms_ny6-00000949", "__MOHCLASS=") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:8] Ringing("SIP/voipms_ny6-00000949", "") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:9] Set("SIP/voipms_ny6-00000949", "__RINGINGSENT=TRUE") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:10] Set("SIP/voipms_ny6-00000949", "__REVERSAL_REJECT=FALSE") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:11] GotoIf("SIP/voipms_ny6-00000949", "1?post-reverse-charge") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx_builtins.c: Goto (from-trunk,5084737699,13)
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:13] NoOp("SIP/voipms_ny6-00000949", "") in new stack
[2017-08-31 12:31:20] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:14] Wait("SIP/voipms_ny6-00000949", "3") in new stack
[2017-08-31 12:31:23] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:15] Set("SIP/voipms_ny6-00000949", "__CALLINGNAMEPRES_SV=allowed_not_screened") in new stack
[2017-08-31 12:31:23] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:16] Set("SIP/voipms_ny6-00000949", "__CALLINGNUMPRES_SV=allowed_not_screened") in new stack
[2017-08-31 12:31:23] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:17] Set("SIP/voipms_ny6-00000949", "CALLERID(name-pres)=allowed_not_screened") in new stack
[2017-08-31 12:31:23] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:18] Set("SIP/voipms_ny6-00000949", "CALLERID(num-pres)=allowed_not_screened") in new stack
[2017-08-31 12:31:23] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:19] NoOp("SIP/voipms_ny6-00000949", "CallerID Entry Point") in new stack
[2017-08-31 12:31:23] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:20] Goto("SIP/voipms_ny6-00000949", "ext-fax,7,1") in new stack
[2017-08-31 12:31:23] VERBOSE[47147][C-00000a2e] pbx_builtins.c: Goto (ext-fax,7,1)
[2017-08-31 12:31:23] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:1] Set("SIP/voipms_ny6-00000949", "FAX_FOR=FAX (7)") in new stack
[2017-08-31 12:31:23] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:2] NoOp("SIP/voipms_ny6-00000949", "Receiving Fax for: FAX (7), From: "4029703226" <4029703226>") in new stack
[2017-08-31 12:31:23] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:3] Set("SIP/voipms_ny6-00000949", "FAX_RX_USER=7") in new stack
[2017-08-31 12:31:23] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:4] Set("SIP/voipms_ny6-00000949", "FAX_RX_EMAIL_LEN=23") in new stack
[2017-08-31 12:31:23] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:5] ExecIf("SIP/voipms_ny6-00000949", "1?Set(ARIUSER=7)") in new stack
[2017-08-31 12:31:23] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:6] ExecIf("SIP/voipms_ny6-00000949", "1?AGI(fax.agi)") in new stack
[2017-08-31 12:31:23] VERBOSE[47147][C-00000a2e] res_agi.c: Launched AGI Script /var/lib/asterisk/agi-bin/fax.agi
[2017-08-31 12:31:23] VERBOSE[47147][C-00000a2e] res_agi.c: <SIP/voipms_ny6-00000949>AGI Script fax.agi completed, returning 0
[2017-08-31 12:31:23] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:7] Goto("SIP/voipms_ny6-00000949", "s,receivefax") in new stack
[2017-08-31 12:31:23] VERBOSE[47147][C-00000a2e] pbx_builtins.c: Goto (ext-fax,s,3)
[2017-08-31 12:31:23] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:3] StopPlayTones("SIP/voipms_ny6-00000949", "") in new stack
[2017-08-31 12:31:23] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:4] ReceiveFAX("SIP/voipms_ny6-00000949", "/var/spool/asterisk/fax/1504197080.5334.tif,f") in new stack
[2017-08-31 12:31:23] VERBOSE[47147][C-00000a2e] res_fax.c: Channel 'SIP/voipms_ny6-00000949' receiving FAX '/var/spool/asterisk/fax/1504197080.5334.tif'
[2017-08-31 12:31:44] VERBOSE[47147][C-00000a2e] pbx.c: Executing [[email protected]:5] ExecIf("SIP/voipms_ny6-00000949", "1?Set(FAXSTATUS="FAILED: error: Disconnected after permitted retries statusstr: Disconnected after permitted retries")") in new stack

Thanks for the link. I am using thee Fax Pro with Fax Detection set = No and a dedicated extension already. The fax works to send and receives from some Fax Senders but not others. I am not sure why the connection to some fax machines is not working. I am hoping someone knows how to get the Fax Pro to work and connect with all Fax machines.

Just so you are aware the inbound functionality is free and is part of faxing, not fax pro.

Thanks so much for your input, I did know the inbound fax was free; however I do need to send faxes so I have installed Fax Pro. By any chance do you have any input on how to configure the inbound faxes so that all fax machines can communicate with them?

It looks like the issue is with T.38 negotiation. As in the far end is not negotiating with you correctly. Sorry I don’t have much help to help you with