Fax errore: FAXSTATUS=FAILED

Hello every body.
First of all I want you to know that I red and searched all over the web and the forums to solve my fax problem, but had no success.
My distro is the last one: Stable 2.210.62-5
The PBX is connected to a Patton 4544 ISDN gateway to a BRI with two line and two number, one dedicated to voice and one to FAX.
The voice inbound and outbound rules work as expected.

I configured FreePBX for FAX as stated by Schmooze, id est:

  1. Fax Configuration
  2. Two inbound routes: one for voice DID and one for FAX DID.
  3. A virtual extension with fax enabled and email configured
  4. the inbound FAX route routed to the FAX virtual extension.

When an incoming fax call arrive on the fax number the PBX answer but after few seconds hung up, this is the log (of course fax number and email are correct i chabged it here in XXXXXXX):

[2013-02-14 19:54:25] VERBOSE[1838] pbx.c: – Executing [[email protected]:1] Set(“SIP/ISDN1-00000129”, “__FROM_DID=XXXXXXXXXX”) in new stack
[2013-02-14 19:54:25] VERBOSE[1838] pbx.c: – Executing [[email protected]:2] Gosub(“SIP/ISDN1-00000129”, “app-blacklist-check,s,1()”) in new stack
[2013-02-14 19:54:25] VERBOSE[1838] pbx.c: – Executing [[email protected]:1] GotoIf(“SIP/ISDN1-00000129”, “0?blacklisted”) in new stack
[2013-02-14 19:54:25] VERBOSE[1838] pbx.c: – Executing [[email protected]:2] Set(“SIP/ISDN1-00000129”, “CALLED_BLACKLIST=1”) in new stack
[2013-02-14 19:54:25] VERBOSE[1838] pbx.c: – Executing [[email protected]:3] Return(“SIP/ISDN1-00000129”, “”) in new stack
[2013-02-14 19:54:25] VERBOSE[1838] pbx.c: – Executing [[email protected]:3] Gosub(“SIP/ISDN1-00000129”, “sub-record-cancel,s,1()”) in new stack
[2013-02-14 19:54:25] VERBOSE[1838] pbx.c: – Executing [[email protected]:1] ExecIf(“SIP/ISDN1-00000129”, “1?Return()”) in new stack
[2013-02-14 19:54:25] VERBOSE[1838] pbx.c: – Executing [[email protected]:4] Set(“SIP/ISDN1-00000129”, “__REC_POLICY_MODE=never”) in new stack
[2013-02-14 19:54:25] VERBOSE[1838] pbx.c: – Executing [[email protected]:5] Set(“SIP/ISDN1-00000129”, “CDR(did)=XXXXXXXXXX”) in new stack
[2013-02-14 19:54:25] VERBOSE[1838] pbx.c: – Executing [[email protected]:6] ExecIf(“SIP/ISDN1-00000129”, “1 ?Set(CALLERID(name)=XXXXXXXXXX)”) in new stack
[2013-02-14 19:54:25] VERBOSE[1838] pbx.c: – Executing [[email protected]:7] Wait(“SIP/ISDN1-00000129”, “10”) in new stack
[2013-02-14 19:54:35] VERBOSE[1838] pbx.c: – Executing [[email protected]:8] Set(“SIP/ISDN1-00000129”, “__CALLINGPRES_SV=allowed_not_screened”) in new stack
[2013-02-14 19:54:35] VERBOSE[1838] pbx.c: – Executing [[email protected]:9] Set(“SIP/ISDN1-00000129”, “CALLERPRES()=allowed_not_screened”) in new stack
[2013-02-14 19:54:35] VERBOSE[1838] pbx.c: – Executing [[email protected]:10] Goto(“SIP/ISDN1-00000129”, “ext-fax,202,1”) in new stack
[2013-02-14 19:54:35] VERBOSE[1838] pbx.c: – Goto (ext-fax,202,1)
[2013-02-14 19:54:35] VERBOSE[1838] pbx.c: – Executing [[email protected]:1] Set(“SIP/ISDN1-00000129”, “FAX_FOR=FAX (202)”) in new stack
[2013-02-14 19:54:35] VERBOSE[1838] pbx.c: – Executing [[email protected]:2] NoOp(“SIP/ISDN1-00000129”, "Receiving Fax for: FAX (202), From: “XXXXXXXXXX” ") in new stack
[2013-02-14 19:54:35] VERBOSE[1838] pbx.c: – Executing [[email protected]:3] Set(“SIP/ISDN1-00000129”, “[email protected]”) in new stack
[2013-02-14 19:54:35] VERBOSE[1838] pbx.c: – Executing [[email protected]:4] Goto(“SIP/ISDN1-00000129”, “s,receivefax”) in new stack
[2013-02-14 19:54:35] VERBOSE[1838] pbx.c: – Goto (ext-fax,s,3)
[2013-02-14 19:54:35] VERBOSE[1838] pbx.c: – Executing [[email protected]:3] StopPlayTones(“SIP/ISDN1-00000129”, “”) in new stack
[2013-02-14 19:54:35] VERBOSE[1838] pbx.c: – Executing [[email protected]:4] ReceiveFAX(“SIP/ISDN1-00000129”, “/var/spool/asterisk/fax/1360868065.297.tif,f”) in new stack
[2013-02-14 19:54:35] VERBOSE[1838] res_fax.c: – Channel ‘SIP/ISDN1-00000129’ receiving FAX ‘/var/spool/asterisk/fax/1360868065.297.tif’
[2013-02-14 19:54:38] VERBOSE[1838] netsock.c: == Using UDPTL TOS bits 184
[2013-02-14 19:54:38] VERBOSE[1838] netsock.c: == Using UDPTL CoS mark 5
[2013-02-14 19:55:01] VERBOSE[1838] pbx.c: – Executing [[email protected]:5] ExecIf(“SIP/ISDN1-00000129”, “1?Set(FAXSTATUS=“FAILED: error: Disconnected after permitted retries statusstr: Disconnected after permitted retries”)”) in new stack
[2013-02-14 19:55:01] VERBOSE[1838] pbx.c: – Executing [[email protected]:6] Hangup(“SIP/ISDN1-00000129”, “”) in new stack
[2013-02-14 19:55:01] VERBOSE[1838] pbx.c: == Spawn extension (ext-fax, s, 6) exited non-zero on ‘SIP/ISDN1-00000129’
[2013-02-14 19:55:01] VERBOSE[1838] pbx.c: – Executing [[email protected]:1] GotoIf(“SIP/ISDN1-00000129”, “1?failed”) in new stack
[2013-02-14 19:55:01] VERBOSE[1838] pbx.c: – Goto (ext-fax,h,103)
[2013-02-14 19:55:01] VERBOSE[1838] pbx.c: – Executing [[email protected]:103] NoOp(“SIP/ISDN1-00000129”, "FAX “FAILED: error: Disconnected after permitted retries statusstr: Disconnected after permitted retries” for: [email protected] , From: “XXXXXXXXXX” ") in new stack
[2013-02-14 19:55:01] VERBOSE[1838] pbx.c: – Executing [[email protected]:104] Macro(“SIP/ISDN1-00000129”, “hangupcall,”) in new stack
[2013-02-14 19:55:01] VERBOSE[1838] pbx.c: – Executing [[email protected]:1] GotoIf(“SIP/ISDN1-00000129”, “1?theend”) in new stack
[2013-02-14 19:55:01] VERBOSE[1838] pbx.c: – Goto (macro-hangupcall,s,3)
[2013-02-14 19:55:01] VERBOSE[1838] pbx.c: – Executing [[email protected]:3] ExecIf(“SIP/ISDN1-00000129”, “0?Set(CDR(recordingfile)=)”) in new stack
[2013-02-14 19:55:01] VERBOSE[1838] pbx.c: – Executing [[email protected]:4] Hangup(“SIP/ISDN1-00000129”, “”) in new stack
[2013-02-14 19:55:01] VERBOSE[1838] app_macro.c: == Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘SIP/ISDN1-00000129’ in macro ‘hangupcall’
[2013-02-14 19:55:01] VERBOSE[1838] pbx.c: == Spawn extension (ext-fax, h, 104) exited non-zero on ‘SIP/ISDN1-00000129’

Hope in your help.

Thank you
JJ

Any chance to get some help?
Thank you
JJ

Hi, I’m just curious: is the .tif file (as per your log above) still available under /var/spool/asterisk/fax/ folder once the incoming FAX arrives and just after the FreePBX hungs up with the error you reported ?

Regards, Davide.

Is the e-mail settings (postfix) side OK (for notification sending) too ?

Hi parnassus,
I did not change anything on postfix side, just left the default settings. The notification email (like update available) are regularly sent.
Do you think that fax configuration needs any change postfix side?

No it isn’t. The fax folder is empty

First of all I’ve to tell you I’m not an expert about FAX management and Asterisk.

What I’m trying to tell you is that I’m curious to see how you will be able to fix this issue because, in a not-so-far future, I will fall in a deployment very similar to your one (a Patton SmartNode 4xxx series as media gateway ISDN BRI/SIP or, eventually, an ISDN BRI PCI Card used to connect with Asterisk/FreePBX) with quite the same FAX requirements and quite the same PSTN side settings (two numbers, one used for Voice calls and the other one used mainly for incoming/outgoing FAX transmission).

Hope four (or more) eyes could help you better than only two.

Could you please post results of these Asterisk CLI’s commands:

  • fax show capabilities
  • fax show settings
  • fax show version

Would also be interesting to understand if there could be a (hidden) issue regarding T.38 negotiation (respect to force using G.711 on the FAX’s SIP peer)…even if I’m not sure this could be a problem by itself.

Regards, Davide.

I forgot to ask you also the result of: sip show settings

Regards, Davide.

First of all thank you for support. About Patton, I spent several hours to configure it, it’s a bit tricky, so whenever you need any help please ask me.
Here the configuration:

fax show capabilities
Registered FAX Technology Modules:
Type : Spandsp
Description : Spandsp FAX Driver
Capabilities : SEND RECEIVE T.38 G.711 GATEWAY
1 registered modules

fax show settings
FAX For Asterisk Settings:
ECM: Enabled
Status Events: Off
Minimum Bit Rate: 2400
Maximum Bit Rate: 14400
Modem Modulations Allowed: V17,V27,V29
FAX Technology Modules:
Spandsp (Spandsp FAX Driver) Settings:

fax show version
FAX For Asterisk Components:
Applications: 10.12.0
Spandsp FAX Driver: 20090502 044449

here you are:

Global Settings:

UDP Bindaddress: 0.0.0.0:5060
TCP SIP Bindaddress: Disabled
TLS SIP Bindaddress: Disabled
Videosupport: No
Textsupport: No
Ignore SDP sess. ver.: No
AutoCreate Peer: No
Match Auth Username: No
Allow unknown access: Yes
Allow subscriptions: Yes
Allow overlap dialing: Yes
Allow promisc. redir: No
Enable call counters: No
SIP domain support: No
Realm. auth: No
Our auth realm asterisk
Use domains as realms: No
Call to non-local dom.: Yes
URI user is phone no: No
Always auth rejects: Yes
Direct RTP setup: No
User Agent: FPBX-2.10.1(10.12.0)
SDP Session Name: Asterisk PBX 10.12.0
SDP Owner Name: root
Reg. context: (not set)
Regexten on Qualify: No
Trust RPID: No
Send RPID: No
Legacy userfield parse: No
Caller ID: Unknown
From: Domain:
Record SIP history: Off
Call Events: Off
Auth. Failure Events: Off
T.38 support: Yes
T.38 EC mode: FEC
T.38 MaxDtgrm: -1
SIP realtime: Disabled
Qualify Freq : 60000 ms
Q.850 Reason header: No
Store SIP_CAUSE: No

Network QoS Settings:

IP ToS SIP: CS3
IP ToS RTP audio: EF
IP ToS RTP video: AF41
IP ToS RTP text: CS0
802.1p CoS SIP: 4
802.1p CoS RTP audio: 5
802.1p CoS RTP video: 6
802.1p CoS RTP text: 5
Jitterbuffer enabled: No

Network Settings:

SIP address remapping: Enabled using externaddr
Externhost:
Externaddr: XXX.XXX.XXX.XXX:0
Externrefresh: 10
Localnet: 192.168.0.0/255.255.255.0

Global Signalling Settings:

Codecs: (gsm|ulaw|alaw)
Codec Order: ulaw:20,alaw:20,gsm:20
Relax DTMF: No
RFC2833 Compensation: No
Symmetric RTP: Yes
Compact SIP headers: No
RTP Keepalive: 0 (Disabled)
RTP Timeout: 30
RTP Hold Timeout: 300
MWI NOTIFY mime type: application/simple-message-summary
DNS SRV lookup: No
Pedantic SIP support: Yes
Reg. min duration 60 secs
Reg. max duration: 3600 secs
Reg. default duration: 120 secs
Outbound reg. timeout: 20 secs
Outbound reg. attempts: 0
Notify ringing state: Yes
Include CID: No
Notify hold state: Yes
SIP Transfer mode: open
Max Call Bitrate: 384 kbps
Auto-Framing: No
Outb. proxy:
Session Timers: Accept
Session Refresher: uas
Session Expires: 1800 secs
Session Min-SE: 90 secs
Timer T1: 500
Timer T1 minimum: 100
Timer B: 32000
No premature media: Yes
Max forwards: 70

Default Settings:

Allowed transports: UDP
Outbound transport: UDP
Context: from-sip-external
Force rport: Yes
DTMF: rfc2833
Qualify: 0
Use ClientCode: No
Progress inband: Never
Language:
MOH Interpret: default
MOH Suggest:
Voice Mail Extension: *97

Maybe I could be wrong but on the log line:

[2013-02-14 19:54:35] VERBOSE[1838] pbx.c: – Executing [[email protected]:4] ReceiveFAX(“SIP/ISDN1-00000129”, “/var/spool/asterisk/fax/1360868065.297.tif,f”) in new stack

appears that the ReceiveFAX command is executed (the synopsis is ReceiveFAX(filename[,options]) with the option f which means “Allow audio fallback FAX transfer on T.38 capable channels.”

There is also no evidence that could be a negotiation’s issue (of T.38) at least because there aren’t error messages regarding T.38 negotiation.

So what’s next ?

Have you tried to rise the log verbosity level on Asterisk CLI before capturing incoming FAX call log ?

What is the content of your /etc/asterisk/sip.conf (the [general] section and the section under which the FAX’s peer is defined) ?

You said that to configure the FAX service on FreePBX you followed what was “…stated by Schmooze”: where is this document/web page/instructions to do so ?

Regards, Davide.

I believe you can set fax debug levels. I would assume these would be ‘fax set debug xxx’ Do a fax ? from the CLI and work out the syntax.

Turning off the dial plan debug with ‘core set verbose 0’ can “declutter” the log. Also make sure you are pulling log out of the /var/log/asterisk/full file. Lastly you can turn on debug, it is extremely verbose and very challenging to read but it is an option “core set debug xx” where xx is an 8 bit integer with each bit position corresponding to a log level “IE: 1 2 3 4 5 6 7 8 position is a log level so a value of 8 would turn on levels 4 and 1, binary decimal values are 1,2,4,8,16,32,64 and 128 respectively”.

If you are going to share these long logs put them on pastebin.ca and just list the link in the forum messages.

Thank you Sky.
i follwed your suggestions:
1.FAX SET DEBUG ON
2.CORE SET VERBOSE 0
3.CORE SET DEBUG 8 (if more is needed please tell me).
4.SENT A FAX
5. COPIED AND PASTED the log: http://pastebin.ca/2316270

Please Davide,
look at pastebin link.

Did you read the log and see you retransmission errors?

Sorry? Which row do you exactly mean and what is a retransmission error?

When you search the log entry you send there are 24 or so hits on the word retransmission.

If you don’t know the definition of a word, look it up in the dictionary.

So some incompatibility exists between your gateway and Asterisk. This stuff is not plug and play. You need to adjust the parameters until you get them to play nicely together. It’s an iterative process and the better you understand the technology the quicker and more successful you are going to be at getting it to work.

We can help with syntax, specific questions about the technology, but it seems as if you are looking for someone to tell you how to fix it. That simply is not going to happen.

Dear Sky,
first of all I want to thank you for your suggestions and solutions so precious and useful. 'Till today I thought that forums were the place where exchange experiences and solutions, in an open and wide community, I discovered today, thanks to you, that is the place where things “are not going to happen”. Many many thanks.
Just a last question, what exactly is a “dictionary”?

Read this fresh one.

Davide.

I gave you some useful information, you focused on the “fluff”.

I am so glad to hear that the time I took was of no value to.

Realize that you have to participate in the process. You have to do more than just provide the output of commands.

Forums provide a great avenue to share experiences, tips and techniques. They are not tech support. I feel as if when I answer a post that ownership is somehow on me to provide a solution. At best you should expect tips or information on how others solved the issue.

I am sorry that my recommendation to utilize a dictionary offended you. If you are working on a communications system and don’t understand the generic concepts of protocol negotiation and retransmission then perhaps your reach has exceeded your grasp.