Fax T.38 to Analog fax Fails But to other SIP faxes Works

First off thank you to everyone who reads this.

We have FreePBX 12.0.76.4 and Asterisk 11

Our server is live and operational and as the subject mentions so long as it is to another SIP Device Fax works. But if its to an analogue device the transfer fails.

T.38 is enabled we can fax to the 1-800-HPFAXME

I have additional logs upon request all the way down to packet level.

Is there anything that i have to configure for T.38 to convert to T.30? Is that even a thing?

I have spent the better part of 5 days trying to figure this out and any help would be much appreciated.

No once the T38 has been accepted on your trunk it will never go back to non T38. Your carrier should handle this for you. If they accept the T38 its now up to them to make sure it can do T38 all the way down and if not then need to do the conversion

Who is your carrier? We are almost permanent residents of FAX Hell but we finally found a carrier and an Asterisk Version going forward that truly is 100% success from and to FAX machines and the box.

What Tony is talking about is that at some point a device in the Path has to be a T.38 Gateway - the device that converts the T.38 Data Packets back into InBand RTP FAX payload - typically your carrier does this.

If you are failing going to T.30 then this is where it is failing.

Here is a Typical Path:

FAX Machine (Analog InBand) -> ATA (Converts to T.38 Data -> Asterisk (Still T.38) -> Carrier (Still T.38) -> Gateway Device on the Carrier Network (Converted to InBand Audio for G.711) -> PSTN (Whoever is there UpStream Carrier) -> Destination PSTN Connection (Still InBand) -> Destination Device

Since you say Pure SIP-2-SIP Connections work, it has to be the Gateway on the Carrier that is choking.

Iristel is our SIP provider.

I appreciate the feedback, Our carrier supports T.38 and claim that everything is working accordingly. Is there logs that i can pull to try and ensure that this if working properly?

I have packet logs as well. I should note that the Logs are about 1667 line (includes Verbose and Debug entries)

I tried to tidy this up as much as possible Extention 666 is the Fax Device (ATA Box (Cisco SPA 122))

since im too new for pastbin links and text si too long i have provided only the bottom half of the log

[details=Summary][2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] netsock2.c: Splitting ‘208.89.128.80:5060’ into…
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] netsock2.c: …host ‘208.89.128.80’ and port ‘5060’.
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Processing session-level SDP v=0… UNSUPPORTED OR FAILED.
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Processing session-level SDP o=BroadWorks 7465663 2 IN IP4 64.30.231.92… OK.
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Processing session-level SDP s=-… UNSUPPORTED OR FAILED.
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] netsock2.c: Splitting ‘64.30.231.92’ into…
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] netsock2.c: …host ‘64.30.231.92’ and port ‘’.
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Processing session-level SDP c=IN IP4 64.30.231.92… OK.
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Processing session-level SDP t=0 0… UNSUPPORTED OR FAILED.
[2016-10-07 17:09:36] VERBOSE[1953][C-00002858] netsock2.c: == Using UDPTL TOS bits 184
[2016-10-07 17:09:36] VERBOSE[1953][C-00002858] netsock2.c: == Using UDPTL CoS mark 5
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Setting NAT on UDPTL to Off
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: FaxVersion: 0
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Processing media-level (image) SDP a=T38FaxVersion:0… OK.
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: T38MaxBitRate: 14400
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Processing media-level (image) SDP a=T38MaxBitRate:14400… OK.
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: MaxBufferSize:1024
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Processing media-level (image) SDP a=T38FaxMaxBuffer:1024… OK.
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Overriding T38FaxMaxDatagram ‘238’ with ‘400’
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: FaxMaxDatagram: 400
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Processing media-level (image) SDP a=T38FaxMaxDatagram:238… OK.
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: UDP EC: t38udpredundancy
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Processing media-level (image) SDP a=T38FaxUdpEC:t38UDPRedundancy… OK.
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: T38 state changed to 2 on channel SIP/Bavmain-00003bac
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Have T.38 but no audio, accepting offer anyway
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: SIP/Bavmain-00003bac: This call is UP…
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Trying to put ‘SIP/2.0 100’ onto UDP socket destined for 208.89.128.80:5060
[2016-10-07 17:09:36] VERBOSE[15936][C-00002858] netsock2.c: == Using UDPTL TOS bits 184
[2016-10-07 17:09:36] VERBOSE[15936][C-00002858] netsock2.c: == Using UDPTL CoS mark 5
[2016-10-07 17:09:36] DEBUG[15936][C-00002858] chan_sip.c: Setting NAT on UDPTL to On
[2016-10-07 17:09:36] DEBUG[15936][C-00002858] chan_sip.c: T38 state changed to 1 on channel SIP/666-00003bab
[2016-10-07 17:09:36] DEBUG[15936][C-00002858] netsock2.c: Splitting ‘192.168.0.252:5060’ into…
[2016-10-07 17:09:36] DEBUG[15936][C-00002858] netsock2.c: …host ‘192.168.0.252’ and port ‘5060’.
[2016-10-07 17:09:36] DEBUG[15936][C-00002858] chan_sip.c: Done building SDP. Settling with this capability: (nothing)
[2016-10-07 17:09:36] DEBUG[15936][C-00002858] chan_sip.c: Initializing already initialized SIP dialog [email protected] (presumably reinvite)
[2016-10-07 17:09:36] DEBUG[15936][C-00002858] chan_sip.c: Trying to put ‘INVITE sip:’ onto UDP socket destined for 192.168.0.252:5060
[2016-10-07 17:09:36] DEBUG[15936][C-00002858] res_rtp_asterisk.c: Setting the marker bit due to a source update
[2016-10-07 17:09:36] WARNING[15936][C-00002858] res_rtp_asterisk.c: RTP Read too short
[2016-10-07 17:09:36] WARNING[15936][C-00002858] res_rtp_asterisk.c: RTP Read too short
[2016-10-07 17:09:36] DEBUG[1953] chan_sip.c: = Looking for Call ID: [email protected] (Checking To) --From tag as4ea62ef1 --To-tag f6f47e29f46749a3o0
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Acked pending invite 102
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Request 102: Match Found
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: SIP response 200 to RE-invite on outgoing call [email protected]
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Processing session-level SDP v=0… UNSUPPORTED OR FAILED.
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Processing session-level SDP o=- 75577 75578 IN IP4 192.168.0.252… OK.
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Processing session-level SDP s=-… UNSUPPORTED OR FAILED.
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] netsock2.c: Splitting ‘192.168.0.252’ into…
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] netsock2.c: …host ‘192.168.0.252’ and port ‘’.
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.0.252… OK.
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Processing session-level SDP t=0 0… UNSUPPORTED OR FAILED.
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: FaxVersion: 0
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Processing media-level (image) SDP a=T38FaxVersion:0… OK.
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: T38MaxBitRate: 14400
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Processing media-level (image) SDP a=T38MaxBitRate:14400… OK.
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: RateManagement: transferredtcf
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Processing media-level (image) SDP a=T38FaxRateManagement:transferredTCF… OK.
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: MaxBufferSize:200
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Processing media-level (image) SDP a=T38FaxMaxBuffer:200… OK.
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Overriding T38FaxMaxDatagram ‘200’ with ‘400’
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: FaxMaxDatagram: 400
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Processing media-level (image) SDP a=T38FaxMaxDatagram:200… OK.
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: UDP EC: t38udpredundancy
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Processing media-level (image) SDP a=T38FaxUdpEC:t38UDPRedundancy… OK.
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: T38 state changed to 3 on channel SIP/666-00003bab
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Have T.38 but no audio, accepting offer anyway
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Updating call counter for incoming call
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] netsock2.c: Splitting ‘192.168.0.252:5060’ into…
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] netsock2.c: …host ‘192.168.0.252’ and port ‘5060’.
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Trying to put ‘ACK sip:666’ onto UDP socket destined for 192.168.0.252:5060
[2016-10-07 17:09:36] DEBUG[1939] devicestate.c: No provider found, checking channel drivers for SIP - 666
[2016-10-07 17:09:36] DEBUG[1939] chan_sip.c: Checking device state for peer 666
[2016-10-07 17:09:36] DEBUG[1939] devicestate.c: Changing state for SIP/666 - state 2 (In use)
[2016-10-07 17:09:36] DEBUG[1939] devicestate.c: device ‘SIP/666’ state ‘2’
[2016-10-07 17:09:36] DEBUG[1977] app_queue.c: Device ‘SIP/666’ changed to state ‘2’ (In use) but we don’t care because they’re not a member of any queue.
[2016-10-07 17:09:36] DEBUG[1941] devicestate.c: Checking if I can find provider for “Custom” - number: DND666
[2016-10-07 17:09:36] DEBUG[1941] devicestate.c: Checking provider SLA with Custom
[2016-10-07 17:09:36] DEBUG[1941] devicestate.c: Checking provider Meetme with Custom
[2016-10-07 17:09:36] DEBUG[1941] devicestate.c: Checking provider Custom with Custom
[2016-10-07 17:09:36] DEBUG[1941] db.c: Unable to find key ‘DND666’ in family ‘CustomDevstate’
[2016-10-07 17:09:36] DEBUG[15936][C-00002858] chan_sip.c: T38 state changed to 3 on channel SIP/Bavmain-00003bac
[2016-10-07 17:09:36] DEBUG[15936][C-00002858] chan_sip.c: Done building SDP. Settling with this capability: (nothing)
[2016-10-07 17:09:36] DEBUG[15936][C-00002858] chan_sip.c: Trying to put ‘SIP/2.0 200’ onto UDP socket destined for 208.89.128.80:5060
[2016-10-07 17:09:36] DEBUG[1953] chan_sip.c: = Looking for Call ID: [email protected] (Checking From) --From tag SDktedc99-815807163-1475874561569 --To-tag as5a740b03
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: **** Received ACK (6) - Command in SIP ACK
[2016-10-07 17:09:36] DEBUG[1953][C-00002858] chan_sip.c: Stopping retransmission on ‘[email protected]’ of Response 276646847: Match Found
[2016-10-07 17:09:41] DEBUG[1953] chan_sip.c: = Looking for Call ID: [email protected] (Checking From) --From tag 518fc4c46f8a47eo0 --To-tag
[2016-10-07 17:09:41] DEBUG[1953] chan_sip.c: **** Received NOTIFY (4) - Command in SIP NOTIFY
[2016-10-07 17:09:41] DEBUG[1953] chan_sip.c: Trying to put ‘SIP/2.0 200’ onto UDP socket destined for 192.168.0.252:5060
[2016-10-07 17:09:42] DEBUG[1953] chan_sip.c: Allocating new SIP dialog for [email protected][::1]:5060 - OPTIONS (No RTP)
[2016-10-07 17:09:42] DEBUG[1953] acl.c: For destination ‘192.168.0.250’, our source address is ‘192.168.0.254’.
[2016-10-07 17:09:42] DEBUG[1953] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.0.254:5060
[2016-10-07 17:09:42] DEBUG[1953] chan_sip.c: SIP call-id changed from ‘[email protected][::1]:5060’ to ‘[email protected]:5060’
[2016-10-07 17:09:42] DEBUG[1953] chan_sip.c: Initializing initreq for method OPTIONS - callid [email protected]:5060
[2016-10-07 17:09:42] DEBUG[1953] chan_sip.c: Trying to put ‘OPTIONS sip’ onto UDP socket destined for 192.168.0.250:5060
[2016-10-07 17:09:42] DEBUG[1953] chan_sip.c: = Looking for Call ID: [email protected]:5060 (Checking To) --From tag as14852ef3 --To-tag 2139773948
[2016-10-07 17:09:42] DEBUG[1953] chan_sip.c: Stopping retransmission on ‘[email protected]:5060’ of Request 102: Match Found
[2016-10-07 17:09:42] DEBUG[1953] chan_sip.c: Destroying SIP dialog [email protected]:5060
[2016-10-07 17:09:44] DEBUG[1953] chan_sip.c: Allocating new SIP dialog for [email protected][::1]:5060 - OPTIONS (No RTP)
[2016-10-07 17:09:44] DEBUG[1953] acl.c: For destination ‘192.168.0.246’, our source address is ‘192.168.0.254’.
[2016-10-07 17:09:44] DEBUG[1953] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 192.168.0.254:5060
[2016-10-07 17:09:44] DEBUG[1953] chan_sip.c: SIP call-id changed from ‘[email protected][::1]:5060’ to ‘[email protected]:5060’
[2016-10-07 17:09:44] DEBUG[1953] chan_sip.c: Initializing initreq for method OPTIONS - callid [email protected]:5060
[2016-10-07 17:09:44] DEBUG[1953] chan_sip.c: Trying to put ‘OPTIONS sip’ onto UDP socket destined for 192.168.0.246:5060
[2016-10-07 17:09:44] DEBUG[1953] chan_sip.c: = Looking for Call ID: [email protected]:5060 (Checking To) --From tag as350fd2c8 --To-tag 827901347
[2016-10-07 17:09:44] DEBUG[1953] chan_sip.c: Stopping retransmission on ‘[email protected]:5060’ of Request 102: Match Found
[2016-10-07 17:09:44] DEBUG[1953] chan_sip.c: Destroying SIP dialog [email protected]:5060
[2016-10-07 17:09:55] VERBOSE[15911] asterisk.c: – Remote UNIX connection disconnected
[2016-10-07 17:10:07] VERBOSE[15936][C-00002858] pbx.c: – Executing [[email protected]:1] Macro(“SIP/666-00003bab”, “hangupcall,”) in new stack
[2016-10-07 17:10:07] VERBOSE[15936][C-00002858] pbx.c: – Executing [[email protected]:1] ExecIf(“SIP/666-00003bab”, “0?Set(CDR(recordingfile)=.wav)”) in new stack
[2016-10-07 17:10:07] VERBOSE[15936][C-00002858] pbx.c: – Executing [[email protected]:2] GotoIf(“SIP/666-00003bab”, “1?theend”) in new stack
[2016-10-07 17:10:07] VERBOSE[15936][C-00002858] pbx.c: – Goto (macro-hangupcall,s,4)
[2016-10-07 17:10:07] VERBOSE[15936][C-00002858] pbx.c: – Executing [[email protected]:4] Hangup(“SIP/666-00003bab”, “”) in new stack
[2016-10-07 17:10:07] VERBOSE[15936][C-00002858] app_macro.c: == Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘SIP/666-00003bab’ in macro ‘hangupcall’
[2016-10-07 17:10:07] VERBOSE[15936][C-00002858] pbx.c: == Spawn extension (macro-dialout-trunk, h, 1) exited non-zero on ‘SIP/666-00003bab’
[2016-10-07 17:10:07] VERBOSE[15936][C-00002858] app_macro.c: == Spawn extension (macro-dialout-trunk, s, 22) exited non-zero on ‘SIP/666-00003bab’ in macro ‘dialout-trunk’
[2016-10-07 17:10:07] VERBOSE[15936][C-00002858] pbx.c: == Spawn extension (from-internal, 14505104079, 6) exited non-zero on ‘SIP/666-00003bab’[/details]

Ask them point blank if you send a t38 fax call and the far end can not take t38 will they convert it for you.

ON it i will reply in the morrow with an update.

Thank you guys you are all awesome :slight_smile:

@tonyclewis SO i asked them point blank, and they said “why of course we do this supported feature” but then said that they would look into the matter.

So using NSE instead of ReINVITE seems to solve the issue for outbound faxing T.38 pass-through on Server but not on the CIsco ATA seems to allow inbound faxing (oddly enough).

I will update if somehting comes of it. I don’t know much about NSE to be honest but it seems like it fixed it.

Updating. After porting numbers to a POTS provider it seems most of the issues were due to poor line quality for the Analogue phones.

Though our SIP provider dosn’t advise the use of Cisco ATA devices.