Inbound fax issues

Hello,

I am running FreePBX v13.0.197.14 (firmware 10.13.66-22) and Asterisk v13.23.1. Up until now, inbound fax-to-email has been working, but my client has reported to me that they have had a couple of their clients try to fax documents and either the entire fax does not come through (only some pages), or it fails.

My client does seem to mostly get faxes OK, but they are only a few pages. The issues seem to occur wih faxes that consist ofseveralpages.

I have been able to reproduce the problem with both a physical fax and a email-to-fax gateway that another client of mine uses. In my testing, I have tried two different multi-page documents: one consisting of 16 pages and the other 9 pages.

Regardless of which document or fax method I try, the whole fax does not go through. The fax is indicated as failed, but a couple of pages of my fax do still make it through, but it is random: sometime it will be the first two or three, but in one case, only page 3 made it through.

I have included a log of my last fax attempt below, which is from a physcial fax machine (IP addresss of my client’s PBX changed). I don’t see anything overtly wrong, but I am not an expert at this either.

Not sure if this points ot a problem with FreePBX, or perhaps the SIP trunk provider. I have opened a ticket with them too, but am just trying to cover all the bases I can.

The only real possible issue I see in the call trace is “WARNING T.30 ECM carrier not found”.

Here is the call trace:

[2019-12-10 16:33:48] VERBOSE[14303][C-00016876] netsock2.c: Using SIP RTP TOS bits 184
[2019-12-10 16:33:48] VERBOSE[14303][C-00016876] netsock2.c: Using SIP RTP CoS mark 5
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:1] Set(“SIP/ThinkTel-SIP-YEG1-0001d781”, “GROUP()=OUT_2”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:2] Goto(“SIP/ThinkTel-SIP-YEG1-0001d781”, “from-trunk,6046838032,1”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx_builtins.c: Goto (from-trunk,6046838032,1)
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:1] Set(“SIP/ThinkTel-SIP-YEG1-0001d781”, “__DIRECTION=INBOUND”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:2] Gosub(“SIP/ThinkTel-SIP-YEG1-0001d781”, “sub-record-check,s,1(in,6046838032,dontcare)”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:1] GotoIf(“SIP/ThinkTel-SIP-YEG1-0001d781”, “0?initialized”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:2] Set(“SIP/ThinkTel-SIP-YEG1-0001d781”, “__REC_STATUS=INITIALIZED”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:3] Set(“SIP/ThinkTel-SIP-YEG1-0001d781”, “NOW=1576024428”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:4] Set(“SIP/ThinkTel-SIP-YEG1-0001d781”, “__DAY=10”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:5] Set(“SIP/ThinkTel-SIP-YEG1-0001d781”, “__MONTH=12”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:6] Set(“SIP/ThinkTel-SIP-YEG1-0001d781”, “__YEAR=2019”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:7] Set(“SIP/ThinkTel-SIP-YEG1-0001d781”, “__TIMESTR=20191210-163348”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:8] Set(“SIP/ThinkTel-SIP-YEG1-0001d781”, “__FROMEXTEN=unknown”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:9] Set(“SIP/ThinkTel-SIP-YEG1-0001d781”, “__MON_FMT=wav”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:10] NoOp(“SIP/ThinkTel-SIP-YEG1-0001d781”, “Recordings initialized”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:11] ExecIf(“SIP/ThinkTel-SIP-YEG1-0001d781”, “0?Set(ARG3=dontcare)”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:12] Set(“SIP/ThinkTel-SIP-YEG1-0001d781”, “REC_POLICY_MODE_SAVE=”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:13] ExecIf(“SIP/ThinkTel-SIP-YEG1-0001d781”, “0?Set(REC_STATUS=NO)”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:14] GotoIf(“SIP/ThinkTel-SIP-YEG1-0001d781”, “2?checkaction”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx_builtins.c: Goto (sub-record-check,s,17)
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:17] GotoIf(“SIP/ThinkTel-SIP-YEG1-0001d781”, “1?sub-record-check,in,1”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx_builtins.c: Goto (sub-record-check,in,1)
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:1] NoOp(“SIP/ThinkTel-SIP-YEG1-0001d781”, “Inbound Recording Check to 6046838032”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:2] Set(“SIP/ThinkTel-SIP-YEG1-0001d781”, “FROMEXTEN=unknown”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:3] ExecIf(“SIP/ThinkTel-SIP-YEG1-0001d781”, “10?Set(FROMEXTEN=7783401109)”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:4] Gosub(“SIP/ThinkTel-SIP-YEG1-0001d781”, “recordcheck,1(dontcare,in,6046838032)”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:1] NoOp(“SIP/ThinkTel-SIP-YEG1-0001d781”, “Starting recording check against dontcare”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:2] Goto(“SIP/ThinkTel-SIP-YEG1-0001d781”, “dontcare”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:3] Return(“SIP/ThinkTel-SIP-YEG1-0001d781”, “”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:5] Return(“SIP/ThinkTel-SIP-YEG1-0001d781”, “”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:3] Set(“SIP/ThinkTel-SIP-YEG1-0001d781”, “__FROM_DID=6046838032”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:4] Set(“SIP/ThinkTel-SIP-YEG1-0001d781”, “returnhere=1”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:5] Gosub(“SIP/ThinkTel-SIP-YEG1-0001d781”, “app-blacklist-check,s,1()”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:1] GotoIf(“SIP/ThinkTel-SIP-YEG1-0001d781”, “0?blacklisted”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:2] Set(“SIP/ThinkTel-SIP-YEG1-0001d781”, “CALLED_BLACKLIST=1”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:3] Return(“SIP/ThinkTel-SIP-YEG1-0001d781”, “”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:6] Set(“SIP/ThinkTel-SIP-YEG1-0001d781”, “CDR(did)=6046838032”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:7] GotoIf(“SIP/ThinkTel-SIP-YEG1-0001d781”, “0?”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:8] ExecIf(“SIP/ThinkTel-SIP-YEG1-0001d781”, “0 ?Set(CALLERID(name)=7783401109)”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]-trunk:9] Set(“SIP/ThinkTel-SIP-YEG1-0001d781”, “__MOHCLASS=”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:10] Set(“SIP/ThinkTel-SIP-YEG1-0001d781”, “__REVERSAL_REJECT=FALSE”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:11] GotoIf(“SIP/ThinkTel-SIP-YEG1-0001d781”, “1?post-reverse-charge”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx_builtins.c: Goto (from-trunk,6046838032,13)
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:13] NoOp(“SIP/ThinkTel-SIP-YEG1-0001d781”, “”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:14] Set(“SIP/ThinkTel-SIP-YEG1-0001d781”, “__CALLINGNAMEPRES_SV=allowed_not_screened”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:15] Set(“SIP/ThinkTel-SIP-YEG1-0001d781”, “__CALLINGNUMPRES_SV=allowed_not_screened”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:16] Set(“SIP/ThinkTel-SIP-YEG1-0001d781”, “CALLERID(name-pres)=allowed_not_screened”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:17] Set(“SIP/ThinkTel-SIP-YEG1-0001d781”, “CALLERID(num-pres)=allowed_not_screened”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:18] NoOp(“SIP/ThinkTel-SIP-YEG1-0001d781”, “CallerID Entry Point”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:19] Set(“SIP/ThinkTel-SIP-YEG1-0001d781”, “FAX_DEST=ext-fax^222^1”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:20] Set(“SIP/ThinkTel-SIP-YEG1-0001d781”, “FAXOPT(faxdetect)=yes”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:21] Answer(“SIP/ThinkTel-SIP-YEG1-0001d781”, “”) in new stack
[2019-12-10 16:33:48] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:22] Wait(“SIP/ThinkTel-SIP-YEG1-0001d781”, “7”) in new stack
[2019-12-10 16:33:50] VERBOSE[8996][C-00016876] res_fax.c: Redirecting ‘SIP/ThinkTel-SIP-YEG1-0001d781’ to fax extension due to CNG detection
[2019-12-10 16:33:50] VERBOSE[8996][C-00016876] pbx.c: Spawn extension (from-trunk, fax, 1) exited non-zero on ‘SIP/ThinkTel-SIP-YEG1-0001d781’
[2019-12-10 16:33:50] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:1] Set(“SIP/ThinkTel-SIP-YEG1-0001d781”, “__DIRECTION=INBOUND”) in new stack
[2019-12-10 16:33:50] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:2] Goto(“SIP/ThinkTel-SIP-YEG1-0001d781”, “ext-fax,222,1”) in new stack
[2019-12-10 16:33:50] VERBOSE[8996][C-00016876] pbx_builtins.c: Goto (ext-fax,222,1)
[2019-12-10 16:33:50] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:1] Set(“SIP/ThinkTel-SIP-YEG1-0001d781”, “FAX_FOR=FAX Metrix (222)”) in new stack
[2019-12-10 16:33:50] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:2] NoOp(“SIP/ThinkTel-SIP-YEG1-0001d781”, “Receiving Fax for: FAX Metrix (222), From: “PSD INC” <7783401109>”) in new stack
[2019-12-10 16:33:50] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:3] Set(“SIP/ThinkTel-SIP-YEG1-0001d781”, “FAX_RX_USER=222”) in new stack
[2019-12-10 16:33:50] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:4] Set(“SIP/ThinkTel-SIP-YEG1-0001d781”, “FAX_RX_EMAIL_LEN=14”) in new stack
[2019-12-10 16:33:50] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:5] Goto(“SIP/ThinkTel-SIP-YEG1-0001d781”, “s,receivefax”) in new stack
[2019-12-10 16:33:50] VERBOSE[8996][C-00016876] pbx_builtins.c: Goto (ext-fax,s,3)
[2019-12-10 16:33:50] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:3] StopPlayTones(“SIP/ThinkTel-SIP-YEG1-0001d781”, “”) in new stack
[2019-12-10 16:33:50] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:4] ReceiveFAX(“SIP/ThinkTel-SIP-YEG1-0001d781”, “/var/spool/asterisk/fax/1576024428.125964.tif,f”) in new stack
[2019-12-10 16:33:50] VERBOSE[8996][C-00016876] res_fax.c: Channel ‘SIP/ThinkTel-SIP-YEG1-0001d781’ receiving FAX ‘/var/spool/asterisk/fax/1576024428.125964.tif’
[2019-12-10 16:34:05] WARNING[14303][C-00016876] chan_sip.c: Failed to initialize UDPTL, declining image stream
[2019-12-10 16:34:05] WARNING[14303][C-00016876] chan_sip.c: Failing due to no acceptable offer found
[2019-12-10 16:34:11] WARNING[8996][C-00016876] res_fax_spandsp.c: WARNING T.30 ECM carrier not found
[2019-12-10 16:34:12] WARNING[8996][C-00016876] res_fax_spandsp.c: WARNING T.30 ECM carrier not found
[2019-12-10 16:34:12] WARNING[8996][C-00016876] res_fax_spandsp.c: WARNING T.30 ECM carrier not found
[2019-12-10 16:35:07] VERBOSE[8996][C-00016876] pbx.c: Spawn extension (ext-fax, s, 4) exited non-zero on ‘SIP/ThinkTel-SIP-YEG1-0001d781’
[2019-12-10 16:35:07] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:1] GotoIf(“SIP/ThinkTel-SIP-YEG1-0001d781”, “1?failed”) in new stack
[2019-12-10 16:35:07] VERBOSE[8996][C-00016876] pbx_builtins.c: Goto (ext-fax,h,104)
[2019-12-10 16:35:07] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:104] NoOp(“SIP/ThinkTel-SIP-YEG1-0001d781”, “FAX FAILED for: FAX Metrix (222) , From: “PSD INC” <7783401109>”) in new stack
[2019-12-10 16:35:07] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:105] Macro(“SIP/ThinkTel-SIP-YEG1-0001d781”, “hangupcall,”) in new stack
[2019-12-10 16:35:07] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:1] GotoIf(“SIP/ThinkTel-SIP-YEG1-0001d781”, “1?theend”) in new stack
[2019-12-10 16:35:07] VERBOSE[8996][C-00016876] pbx_builtins.c: Goto (macro-hangupcall,s,3)
[2019-12-10 16:35:07] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:3] ExecIf(“SIP/ThinkTel-SIP-YEG1-0001d781”, “0?Set(CDR(recordingfile)=)”) in new stack
[2019-12-10 16:35:07] VERBOSE[8996][C-00016876] pbx.c: Executing [[email protected]:4] Hangup(“SIP/ThinkTel-SIP-YEG1-0001d781”, “”) in new stack
[2019-12-10 16:35:07] VERBOSE[8996][C-00016876] app_macro.c: Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘SIP/ThinkTel-SIP-YEG1-0001d781’ in macro ‘hangupcall’
[2019-12-10 16:35:07] VERBOSE[8996][C-00016876] pbx.c: Spawn extension (ext-fax, h, 105) exited non-zero on ‘SIP/ThinkTel-SIP-YEG1-0001d781’

What ports do you have open for udptl on your firewall?
Who is the Underlying origination provider for your dids?

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