[Home]

Summary:ASTERISK-14531: [patch] Failure to negotiate T.38
Reporter:Scott Johnson (globalnetinc)Labels:
Date Opened:2009-07-26 15:57:38Date Closed:2009-10-05 18:11:16
Priority:BlockerRegression?No
Status:Closed/CompleteComponents:Channels/chan_sip/T.38
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) Digium.zip
( 1) failfax-1.6.0.15.pcap
( 2) failfax-1.6.0-svn-Patched.pcap
( 3) FaxBufferIssue.pcap
( 4) FaxComplete-1.6.1.0.zip
( 5) faxcomplete-1.6.10.pcap
( 6) FaxFail-1.6.0-svn-Patched.zip
( 7) full.1
( 8) full.report
( 9) issue-15586.patch
(10) udptl.c
(11) ver-1.6.2-svn-current.pcap
Description:To implement T.38 on most ATAs their is a reinvite required.  In the process of gatewaying the T.38 negotiations the Asterisk server is not doing this correctly.  On versions past 1.6.0.10 it does not even send the same ports on the RTP streams to both parties.  

Every version past 1.6.0.10 fails
1.6.0.11
1.6.1.0
1.6.1.1
1.6.2.0-rc

This also includes the new T.38 stack that is is being introduced. in the SVN tree of 1.6.1.1 and 1.6.2.0

****** ADDITIONAL INFORMATION ******

Caller (Linksys SPA2102, Grandstream HT502, AudioCodes MP 202) -=> Asterisk server -=> Sip Server (Sonus)
Comments:By: Scott Johnson (globalnetinc) 2009-07-30 09:49:35

Here is an example in 1.6.2-beta3

INVITE sip:4065877430@216.166.170.179:5060 SIP/2.0M
Via: SIP/2.0/UDP 216.166.168.6:5060;branch=z9hG4bK0e1a10f6;rportM
Max-Forwards: 70M
From: <sip:5864348@216.166.168.6>;tag=as5701e186M
To: The Johnson Company <sip:4065877430@216.166.168.6>;tag=dfd89b08f93f9771o1M
Contact: <sip:5864348@216.166.168.6>M
Call-ID: d1eec814-13e26dd5@216.166.170.179M
CSeq: 103 INVITEM
User-Agent: Asterisk PBXM
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFOM
Supported: replaces, timerM
X-asterisk-Info: SIP re-invite (External RTP bridge)M
Content-Type: application/sdpM
Content-Length: 264M
M
v=0M
o=root 1412831342 1412831346 IN IP4 66.62.196.38M
s=Asterisk PBXM
c=IN IP4 66.62.196.38M
t=0 0M
m=image 14648 udptl t38M
a=T38Faxversion:0M
a=T38MaxBitRate:14400M
a=T38FaxRateManagement:transferredTCFM
a=T38FaxMaxDatagram:165M
a=T38FaxUdpEC:t38UDPRedundancyM

---
[Jul 30 00:12:07] VERBOSE[24901] logger.c:
<--- SIP read from UDP://216.166.170.179:5060 --->
SIP/2.0 200 OKM
To: The Johnson Company <sip:4065877430@216.166.168.6>;tag=dfd89b08f93f9771o1M
From: <sip:5864348@216.166.168.6>;tag=as5701e186M
Call-ID: d1eec814-13e26dd5@216.166.170.179M
CSeq: 103 INVITEM
Via: SIP/2.0/UDP 216.166.168.6:5060;branch=z9hG4bK0e1a10f6M
Contact: The Johnson Company <sip:4065877430@216.166.170.179:5060>M
Server: Linksys/SPA2102-5.2.5M
Content-Length: 275M
Content-Type: application/sdpM
M
v=0M
o=- 22383364 22383364 IN IP4 216.166.170.179M
s=-M
c=IN IP4 216.166.170.179M
t=0 0M
m=image 16394 udptl t38M
a=T38FaxVersion:0M
a=T38MaxBitRate:14400M
a=T38FaxRateManagement:transferredTCFM
a=T38FaxMaxBuffer:200M
a=T38FaxMaxDatagram:200M
a=T38FaxUdpEC:t38UDPRedundancyM

<------------->
[Jul 30 00:12:07] VERBOSE[24901] logger.c: --- (10 headers 12 lines) ---
[Jul 30 00:12:07] VERBOSE[24901] logger.c: Got T.38 offer in SDP in dialog d1eec814-13e26dd5@216.166.170.179
[Jul 30 00:12:07] VERBOSE[24901] logger.c: Got T.38 Re-invite without audio. Keeping RTP active during T.38 session. Callid d1eec814-13e26dd5@216.166.170.179
[Jul 30 00:12:07] VERBOSE[24901] logger.c: Capabilities: us - 0x114 (ulaw|g729|g726), peer - audio=0x0 (nothing)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x0 (nothing)
[Jul 30 00:12:07] VERBOSE[24901] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x0 (nothing), combined - 0x0 (nothing)
[Jul 30 00:12:07] VERBOSE[24901] logger.c: set_destination: Parsing <sip:4065877430@216.166.170.179:5060> for address/port to send to
[Jul 30 00:12:07] VERBOSE[24901] logger.c: set_destination: set destination to 216.166.170.179, port 5060
[Jul 30 00:12:07] VERBOSE[24901] logger.c: Transmitting (no NAT) to 216.166.170.179:5060:

Then you see this error:
WARNING[16385] udptl.c: UDPTL asked to send 41 bytes of IFP when far end only prepared to accept 31 bytes; data loss may occur.
By: Kevin P. Fleming (kpfleming) 2009-08-21 14:26:50

Your comments are confusing; first, let me address the simple one... you say Asterisk does not send the same ports on the RTP streams to both parties. RTP is not used for T.38 FAX, UDPTL is used, but in spite of that, since Asterisk is a B2BUA, there is no need nor expectation that the two channel legs involved will use the same port numbers for their UDPTL streams.

Now, on to the real issue: Asterisk sent an INVITE with a T38FaxMaxDatagram value of '165', and a T38FaxUdpEC value of 't38UDPRedundancy'. This means that it is prepared for (and expects) us to send redundant IFPs in our UDPTL frames as an error correction mechamism. The default in the T.38 recommendation, and in Asterisk, is to send 3 redundancy frames. To accommodate this situation, Asterisk's UDPTL code devices the maximum datagram size the endpoint can accept by the number of IFPs we have to be able to send, subtracts a small amount for overhead, and uses that to ensure we are never supplied an IFP that we won't be able to fit into the UDPTL frame.

Since you didn't include a full packet trace (with the originating T.38 INVITE that caused Asterisk to send a T.38 INVITE to the Linksys device), we can't see what the Sonus endpoint sent, but I suspect it sent a small T38FaxMaxDatagram value, which caused Asterisk to have to do the same thing. In essence, this is a problem with the incoming INVITE, but you'll have to post a full packet trace (as an attachment, not a bugnote) to be able to verify that.
By: Mark Hulber (hulber) 2009-08-21 14:53:22

I had recently set up T.38 passthrough using 1.6.0.9 and tried faxing today with versions 1.6.1.4 and 1.6.0.13 with no luck. It appears not to even negotiate although I see the provider indicating the call should be T38.

Dropping back to 1.6.0.9 to see if it works again as soon as I can restart Asterisk.
By: Mark Hulber (hulber) 2009-08-21 15:23:57

After dropping back to 1.6.0.9 T.38 negotiates and fax is successful.  I can move back up and provide a trace if desired.
By: Kevin P. Fleming (kpfleming) 2009-08-21 15:34:37

That would be excellent; if you can test the tip of the 1.6.0 branch in Subversion, and attach a console log that was made with *all* logger levels enabled (including debug and verbose) and 'core set verbose 10', 'core set debug 10', and 'sip set debug on' that should include all the information needed to diagnose the problem. Thanks.
By: Mark Hulber (hulber) 2009-08-21 16:16:20

Full log attached.  There is a failed fax in this trace.  There is never a negotiation with the fax device.

Asterisk SVN-branch-1.6.0-r213561 built by root on a x86_64 running Linux on 2009-08-21 20:44:19 UTC
By: Kevin P. Fleming (kpfleming) 2009-08-21 17:06:39

I'm not sure what you mean by 'there is never a negotiation with the fax device', but I can see that there is a problem here. The Sipura device initiated the switch to T.38, Asterisk initiates a switch with your carrier, the carrier accepts, Asterisk accepts the switch with the Sipura device, then for some reason immediately switches back to audio mode. I'll continue investigating.
By: Mark Hulber (hulber) 2009-08-22 06:11:57

I just mean that the local fax machine never recognizes that there is a remote fax machine notwithstanding any negotiation that is going on underneath.
By: Kevin P. Fleming (kpfleming) 2009-08-24 10:35:20

Would you mind trying the attached (small) patch on the 1.6.0 branch you last tested on? If it works, we'll know what the cause of this problem is and can come up with a solution. Thanks!
By: Scott Johnson (globalnetinc) 2009-08-25 10:33:25

To further explain the issue above.  Any released version beyond 1.6.0.10 does not allow a T.38 connection negotiate correctly to the SIP provider.  In the versions with the revised T.38 stack you will see:

[Jul 30 01:58:13] WARNING[16385] udptl.c: UDPTL asked to send 41 bytes of IFP when far end only prepared to accept 31 bytes; data loss may occur.
[Jul 30 01:58:13] ERROR[16385] udptl.c: Buffer overflow detected (48 + 131 > 176)
[Jul 30 01:58:13] NOTICE[16385] udptl.c: UDPTL Transmission error to 66.62.196.38:59166: Message too long
[Jul 30 01:58:13] WARNING[16385] udptl.c: UDPTL asked to send 41 bytes of IFP when far end only prepared to accept 31 bytes; data loss may occur.

This causes the symptom hulber reported above.  I believe that this is also reported in issue 15649.  The Sip truck provider is using SONUS.  I believe this to be an issue with them but as usual they are big we are small so it is up to us to create a work-around.


By: Kevin P. Fleming (kpfleming) 2009-08-25 15:17:53

That is correct, and that's why I've asked the reporter to test the tip of the 1.6.0 branch, and not the most recent released version. There have been changes in T.38 support *after* 1.6.0.10 was made (and 1.6.0.13/14 were just security releases so their T.38 support is identical to 1.6.0.10), and one of those changes was to try to accommodate T.38 endpoints that report ridiculously small T38FaxMaxDatagram values. This *is* the workaround you are asking for, but we need testing to ensure that it solves the problem.
By: Mark Hulber (hulber) 2009-08-25 15:57:18

Haven't had a chance yet but I'll try asap.
By: Scott Johnson (globalnetinc) 2009-08-26 00:13:00

Yep but I was the report at the top if you will check.  Also ver 1.6.0.10 does work for the most part.  It was beyond that the failed.  I am currently running 1.6.0.10.  It does work.  1.6.1.1 and up. 1.6.2.x and 1.6.0.11 and up all failed.

At his point you believe that the current versions from
http://svn.digium.com/svn/asterisk/branches/1.6.0
http://svn.digium.com/svn/asterisk/branches/1.6.1
http://svn.digium.com/svn/asterisk/branches/1.6.2

all are fixed?

If so I will test them all
By: Kevin P. Fleming (kpfleming) 2009-08-26 11:04:45

The T.38 signaling code in all the 1.6 branches is identical, so if it works in one it will work in all of them... no need to test them all individually.
By: Scott Johnson (globalnetinc) 2009-08-26 19:31:08

Okay I will pull the code down and run it.  Thanks.
By: Scott Johnson (globalnetinc) 2009-08-27 16:44:00

This is in the log.... on Asterisk SVN-branch-1.6.2-r214356M
[Aug 27 15:39:08] NOTICE[16929]: udptl.c:1014 ast_udptl_write: UDPTL Transmission error to 216.166.168.17:49154: Message too long
[Aug 27 15:39:09] ERROR[16929]: udptl.c:292 encode_open_type: Buffer overflow detected (47 + 35 > 72)
[Aug 27 15:39:09] NOTICE[16929]: udptl.c:1014 ast_udptl_write: UDPTL Transmission error to 216.166.168.17:49154: Message too long
[Aug 27 15:39:09] ERROR[16929]: udptl.c:292 encode_open_type: Buffer overflow detected (47 + 35 > 72)
[Aug 27 15:39:09] NOTICE[16929]: udptl.c:1014 ast_udptl_write: UDPTL Transmission error to 216.166.168.17:49154: Message too long
[Aug 27 15:39:09] ERROR[16929]: udptl.c:292 encode_open_type: Buffer overflow detected (47 + 35 > 72)
[Aug 27 15:39:09] NOTICE[16929]: udptl.c:1014 ast_udptl_write: UDPTL Transmission error to 216.166.168.17:49154: Message too long
[Aug 27 15:39:09] ERROR[16929]: udptl.c:292 encode_open_type: Buffer overflow detected (47 + 35 > 72)
[Aug 27 15:39:09] NOTICE[16929]: udptl.c:1014 ast_udptl_write: UDPTL Transmission error to 216.166.168.17:49154: Message too long
[Aug 27 15:39:09] ERROR[16929]: udptl.c:292 encode_open_type: Buffer overflow detected (47 + 35 > 72)
[Aug 27 15:39:09] NOTICE[16929]: udptl.c:1014 ast_udptl_write: UDPTL Transmission error to 216.166.168.17:49154: Message too long
[Aug 27 15:39:09] ERROR[16929]: udptl.c:292 encode_open_type: Buffer overflow detected (47 + 35 > 72)
[Aug 27 15:39:09] NOTICE[16929]: udptl.c:1014 ast_udptl_write: UDPTL Transmission error to 216.166.168.17:49154: Message too long
[Aug 27 15:39:09] ERROR[16929]: udptl.c:292 encode_open_type: Buffer overflow detected (47 + 46 > 72)
[Aug 27 15:39:09] NOTICE[16929]: udptl.c:1014 ast_udptl_write: UDPTL Transmission error to 216.166.168.17:49154: Message too long


I have also uploaded a pcap file


By: Scott Johnson (globalnetinc) 2009-08-27 17:59:19

These errors do not occur on 1.6.0.10 and the fax goes through fine.
By: Scott Johnson (globalnetinc) 2009-08-28 11:27:01

For clarification.
216.166.170.179 is a linksys ata => 216.166.170.1 a router
216.166.168.6 Asterisk system
216.166.168.17 fax server

You will see packets to an from 216.166.170.x twice because all of these were put on on hub not and the packets must go through the router to get to the ATA
By: Scott Johnson (globalnetinc) 2009-08-28 18:41:14

Took and changed the min calculated value

static void calculate_far_max_ifp(struct ast_udptl *udptl)
{
       unsigned new_max = 180;

It did not change the error.

[Aug 28 17:38:34] ERROR[11367]: udptl.c:292 encode_open_type: Buffer overflow detected (53 + 51 > 72)
[Aug 28 17:38:34] NOTICE[11367]: udptl.c:1020 ast_udptl_write: UDPTL Transmission error to 216.166.168.17:49154: Message too long
By: Scott Johnson (globalnetinc) 2009-08-28 19:19:43

I also see this with the debug on

<< [ TYPE: Control (4) SUBCLASS: T38_Parameters/Invalid (24) ] [SIP/myfax-0855d610]
<< [ TYPE: Control (4) SUBCLASS: T38_Parameters/Invalid (24) ] [SIP/4065877430-08720640]
<< [ TYPE: Control (4) SUBCLASS: T38_Parameters/Invalid (24) ] [SIP/myfax-0855d610]
By: Kevin P. Fleming (kpfleming) 2009-09-01 15:27:42

Those frame dump messages saying 'Invalid' were an unrelated bug; that has been fixed.

There was a logic error in the way the code tried to override the far end's max datagram value; the attached patch should fix that, and get your FAXes working again.
By: Mark Hulber (hulber) 2009-09-01 16:32:11

Tried last patch and attached log.  Still unable to fax.
By: Scott Johnson (globalnetinc) 2009-09-01 22:01:30

I have installed the patch on 1.6.2.0-rc1 and will let you know.  As for a better way to calc:

If we know the max rate (14400) can we not calculate the packet size from that and instead of believing the false data passed to us?
By: Scott Johnson (globalnetinc) 2009-09-01 22:28:55

I added a line to dump the value being used on line 790
       udptl->far_max_ifp = new_max * 0.75;

Line 791 is:
       ast_log(LOG_NOTICE, "UDPTL IFP far end calculated to accept %d bytes.\n", new_max);

How is it that we can get a value of 48??????

[Sep  1 21:13:00] NOTICE[14248]: udptl.c:791 calculate_far_max_ifp: UDPTL IFP far end calculated to accept 48 bytes.
By: Scott Johnson (globalnetinc) 2009-09-02 09:26:39

I have uploaded a patched version of udptl.c.  Sorry I did not create a dif.  Before I patched it the code was shrinking the IPF size if it did not have a value in the max_datagram.  This would cause it to get smaller as reported by the debug lines I entered.

[Sep  2 01:13:12] NOTICE[1657]: udptl.c:760 calculate_far_max_datagram_limit: UDPTL T38FaxMaxDatagram far end reported to accept 200 bytes.
[Sep  2 01:13:12] NOTICE[1657]: udptl.c:761 calculate_far_max_datagram_limit: UDPTL T38FaxIFP far end reported to accept 83 bytes.
[Sep  2 01:13:12] NOTICE[1657]: udptl.c:797 calculate_far_max_ifp: UDPTL far end ERROR CORRECTION reported as 2 .
[Sep  2 01:13:12] NOTICE[1657]: udptl.c:798 calculate_far_max_ifp: UDPTL IFP far end calculated to accept 48 bytes.
By: Scott Johnson (globalnetinc) 2009-09-02 10:13:25

I also see this from my debug.  Should this happen?  How can there be a T.38 call and no information

[Sep  2 09:11:10] NOTICE[6506]: udptl.c:760 calculate_far_max_datagram_limit: UDPTL T38FaxMaxDatagram far end reported to accept 0 bytes.
[Sep  2 09:11:10] NOTICE[6506]: udptl.c:761 calculate_far_max_datagram_limit: UDPTL T38FaxIFP far end reported to accept 0 bytes.
[Sep  2 09:11:10] NOTICE[6506]: udptl.c:799 calculate_far_max_ifp: UDPTL far end ERROR CORRECTION reported as 1 .
By: Scott Johnson (globalnetinc) 2009-09-02 11:13:02

I still see this error when talking to certain devices.  I have attached a pcap file called faxbufferissue that shows the packets sent.

216.166.168.6 is asterisk
216.166.168.183 is an ATA
216.166.168.17 is a fax server

[Sep  2 10:07:52] WARNING[25127]: udptl.c:1033 ast_udptl_write: UDPTL asked to send 53 bytes of IFP when far end only prepared to accept 48 bytes; data loss may occur.
[Sep  2 10:07:52] ERROR[25127]: udptl.c:299 encode_open_type: Buffer overflow detected (53 + 167 > 200)
By: Scott Johnson (globalnetinc) 2009-09-02 11:16:11

Just to be clear.  If I return the asterisk version to 1.6.0.10 then the exact same devices send and receive faxes without failure.
By: Scott Johnson (globalnetinc) 2009-09-02 12:23:21

Last question... Why would there ever be a case where:

[Sep  2 11:21:17] NOTICE[29108]: udptl.c:760 calculate_far_max_datagram_limit: UDPTL T38FaxMaxDatagram far end reported to accept 0 bytes.
[Sep  2 11:21:17] NOTICE[29108]: udptl.c:761 calculate_far_max_datagram_limit: UDPTL T38FaxIFP far end reported to accept 0 bytes.
[Sep  2 11:21:17] NOTICE[29108]: udptl.c:799 calculate_far_max_ifp: UDPTL far end ERROR CORRECTION reported as 1 .
By: Scott Johnson (globalnetinc) 2009-09-10 11:48:11

still looking for ideas.
By: Hendrik van der Ploeg (elsto) 2009-09-16 09:08:57

Just wanted to let you guys know;

issue-15586.patch solved my problem on Asterisk-1.6.1.6

Thanks a lot guys!
By: Kristijan Vrban (vrban) 2009-09-17 08:59:08

@globalnetinc

what happen when you set the receiving analog fax fixed to 9600bps ?

because in my T.38 test setup:
asterisk-trunk(219105) SendFax(spandsp-20090714) ----> Linksys Spa-2102 ----> analog fax (brother FAX-2820)

When the analog fax (brother FAX-2820) is set to it's max speed 14400, i get this errors, but fax transmission is ok:

...
[Sep 17 15:26:16] ERROR[3539]: udptl.c:292 encode_open_type: Buffer overflow detected (50 + 158 > 200)
[Sep 17 15:26:16] WARNING[3539]: udptl.c:1003 ast_udptl_write: UDPTL asked to send 50 bytes of IFP when far end only prepared to accept 45 bytes; data loss may occur.
[Sep 17 15:26:16] ERROR[3539]: udptl.c:292 encode_open_type: Buffer overflow detected (50 + 158 > 200)
[Sep 17 15:26:16] WARNING[3539]: udptl.c:1003 ast_udptl_write: UDPTL asked to send 50 bytes of IFP when far end only prepared to accept 45 bytes; data loss may occur.
[Sep 17 15:26:16] ERROR[3539]: udptl.c:292 encode_open_type: Buffer overflow detected (50 + 158 > 200)
[Sep 17 15:26:16] WARNING[3539]: udptl.c:1003 ast_udptl_write: UDPTL asked to send 50 bytes of IFP when far end only prepared to accept 45 bytes; data loss may occur.
[Sep 17 15:26:16] ERROR[3539]: udptl.c:292 encode_open_type: Buffer overflow detected (50 + 158 > 200)
test-pbx01*CLI>
   -- Executing [s@t38-faxout:4] NoOp("SIP/10-08471b90", "###       FAXSTATUS: SUCCESS") in new stack
   -- Executing [s@t38-faxout:5] NoOp("SIP/10-08471b90", "###        FAXERROR: ") in new stack
   -- Executing [s@t38-faxout:6] NoOp("SIP/10-08471b90", "###         FAXMODE: T38") in new stack
   -- Executing [s@t38-faxout:7] NoOp("SIP/10-08471b90", "###        FAXPAGES: 1") in new stack
   -- Executing [s@t38-faxout:8] NoOp("SIP/10-08471b90", "###      FAXBITRATE: 9600") in new stack  
   -- Executing [s@t38-faxout:9] NoOp("SIP/10-08471b90", "###   FAXRESOLUTION: 3850") in new stack


When the analog fax (brother FAX-2820) is set to it's safe speed 9600, i get no errors:

   -- Executing [s@t38-faxout:4] NoOp("SIP/10-08471b90", "###       FAXSTATUS: SUCCESS") in new stack
   -- Executing [s@t38-faxout:5] NoOp("SIP/10-08471b90", "###        FAXERROR: ") in new stack
   -- Executing [s@t38-faxout:6] NoOp("SIP/10-08471b90", "###         FAXMODE: T38") in new stack
   -- Executing [s@t38-faxout:7] NoOp("SIP/10-08471b90", "###        FAXPAGES: 1") in new stack
   -- Executing [s@t38-faxout:8] NoOp("SIP/10-08471b90", "###      FAXBITRATE: 9600") in new stack
   -- Executing [s@t38-faxout:9] NoOp("SIP/10-08471b90", "###   FAXRESOLUTION: 3850") in new stack


By: Kristijan Vrban (vrban) 2009-09-17 09:21:37

With issue-15586.patch and analog fax (brother FAX-2820) is set to it's safe speed 9600, i get
   
[Sep 17 16:06:34] WARNING[10255]: udptl.c:1021 ast_udptl_write: UDPTL asked to send 41 bytes of IFP when far end only prepared to accept 36 bytes; data loss may occur.
[Sep 17 16:06:34] WARNING[10255]: udptl.c:1021 ast_udptl_write: UDPTL asked to send 41 bytes of IFP when far end only prepared to accept 36 bytes; data loss may occur.
[Sep 17 16:06:34] WARNING[10255]: udptl.c:1021 ast_udptl_write: UDPTL asked to send 41 bytes of IFP when far end only prepared to accept 36 bytes; data loss may occur.
[Sep 17 16:06:34] WARNING[10255]: udptl.c:1021 ast_udptl_write: UDPTL asked to send 41 bytes of IFP when far end only prepared to accept 36 bytes; data loss may occur.
[Sep 17 16:06:34] WARNING[10255]: udptl.c:1021 ast_udptl_write: UDPTL asked to send 41 bytes of IFP when far end only prepared to accept 36 bytes; data loss may occur.
[Sep 17 16:06:34] WARNING[10255]: udptl.c:1021 ast_udptl_write: UDPTL asked to send 41 bytes of IFP when far end only prepared to accept 36 bytes; data loss may occur.
   -- Executing [s@t38-faxout:4] NoOp("SIP/10-088f34e8", "###       FAXSTATUS: SUCCESS") in new stack
   -- Executing [s@t38-faxout:5] NoOp("SIP/10-088f34e8", "###        FAXERROR: ") in new stack
   -- Executing [s@t38-faxout:6] NoOp("SIP/10-088f34e8", "###         FAXMODE: T38") in new stack
   -- Executing [s@t38-faxout:7] NoOp("SIP/10-088f34e8", "###        FAXPAGES: 1") in new stack
   -- Executing [s@t38-faxout:8] NoOp("SIP/10-088f34e8", "###      FAXBITRATE: 9600") in new stack
   -- Executing [s@t38-faxout:9] NoOp("SIP/10-088f34e8", "###   FAXRESOLUTION: 3850") in new stack
   
   
   
With issue-15586.patch and analog fax (brother FAX-2820) is set to it's max speed 14400, i get
   
...
[Sep 17 16:12:56] ERROR[10379]: udptl.c:299 encode_open_type: Buffer overflow detected (50 + 158 > 200)
[Sep 17 16:12:56] WARNING[10379]: udptl.c:1021 ast_udptl_write: UDPTL asked to send 50 bytes of IFP when far end only prepared to accept 36 bytes; data loss may occur.
[Sep 17 16:12:56] ERROR[10379]: udptl.c:299 encode_open_type: Buffer overflow detected (50 + 158 > 200)
[Sep 17 16:12:56] WARNING[10379]: udptl.c:1021 ast_udptl_write: UDPTL asked to send 50 bytes of IFP when far end only prepared to accept 36 bytes; data loss may occur.
[Sep 17 16:12:56] ERROR[10379]: udptl.c:299 encode_open_type: Buffer overflow detected (50 + 158 > 200)
[Sep 17 16:12:56] WARNING[10379]: udptl.c:1021 ast_udptl_write: UDPTL asked to send 50 bytes of IFP when far end only prepared to accept 36 bytes; data loss may occur.
[Sep 17 16:12:56] ERROR[10379]: udptl.c:299 encode_open_type: Buffer overflow detected (50 + 158 > 200)
[Sep 17 16:12:56] WARNING[10379]: udptl.c:1021 ast_udptl_write: UDPTL asked to send 50 bytes of IFP when far end only prepared to accept 36 bytes; data loss may occur.
[Sep 17 16:12:56] ERROR[10379]: udptl.c:299 encode_open_type: Buffer overflow detected (50 + 158 > 200)
[Sep 17 16:12:56] WARNING[10379]: udptl.c:1021 ast_udptl_write: UDPTL asked to send 50 bytes of IFP when far end only prepared to accept 36 bytes; data loss may occur.
[Sep 17 16:12:56] ERROR[10379]: udptl.c:299 encode_open_type: Buffer overflow detected (50 + 158 > 200)
[Sep 17 16:12:56] WARNING[10379]: udptl.c:1021 ast_udptl_write: UDPTL asked to send 50 bytes of IFP when far end only prepared to accept 36 bytes; data loss may occur.
[Sep 17 16:12:56] ERROR[10379]: udptl.c:299 encode_open_type: Buffer overflow detected (50 + 158 > 200)
[Sep 17 16:12:56] WARNING[10379]: udptl.c:1021 ast_udptl_write: UDPTL asked to send 50 bytes of IFP when far end only prepared to accept 36 bytes; data loss may occur.
[Sep 17 16:12:56] ERROR[10379]: udptl.c:299 encode_open_type: Buffer overflow detected (50 + 158 > 200)
[Sep 17 16:13:02] WARNING[10379]: udptl.c:1021 ast_udptl_write: UDPTL asked to send 41 bytes of IFP when far end only prepared to accept 36 bytes; data loss may occur.
   -- Remote UNIX connection disconnected
[Sep 17 16:13:02] WARNING[10379]: udptl.c:1021 ast_udptl_write: UDPTL asked to send 41 bytes of IFP when far end only prepared to accept 36 bytes; data loss may occur.
[Sep 17 16:13:02] WARNING[10379]: udptl.c:1021 ast_udptl_write: UDPTL asked to send 41 bytes of IFP when far end only prepared to accept 36 bytes; data loss may occur.
[Sep 17 16:13:02] WARNING[10379]: udptl.c:1021 ast_udptl_write: UDPTL asked to send 41 bytes of IFP when far end only prepared to accept 36 bytes; data loss may occur.
[Sep 17 16:13:02] WARNING[10379]: udptl.c:1021 ast_udptl_write: UDPTL asked to send 41 bytes of IFP when far end only prepared to accept 36 bytes; data loss may occur.
[Sep 17 16:13:02] WARNING[10379]: udptl.c:1021 ast_udptl_write: UDPTL asked to send 41 bytes of IFP when far end only prepared to accept 36 bytes; data loss may occur.
[Sep 17 16:13:02] WARNING[10379]: udptl.c:1021 ast_udptl_write: UDPTL asked to send 41 bytes of IFP when far end only prepared to accept 36 bytes; data loss may occur.
[Sep 17 16:13:02] WARNING[10379]: udptl.c:1021 ast_udptl_write: UDPTL asked to send 41 bytes of IFP when far end only prepared to accept 36 bytes; data loss may occur.
[Sep 17 16:13:02] WARNING[10379]: udptl.c:1021 ast_udptl_write: UDPTL asked to send 41 bytes of IFP when far end only prepared to accept 36 bytes; data loss may occur.
[Sep 17 16:13:02] WARNING[10379]: udptl.c:1021 ast_udptl_write: UDPTL asked to send 41 bytes of IFP when far end only prepared to accept 36 bytes; data loss may occur.
...
   -- Executing [s@t38-faxout:4] NoOp("SIP/10-088f34e8", "###       FAXSTATUS: SUCCESS") in new stack
   -- Executing [s@t38-faxout:5] NoOp("SIP/10-088f34e8", "###        FAXERROR: ") in new stack
   -- Executing [s@t38-faxout:6] NoOp("SIP/10-088f34e8", "###         FAXMODE: T38") in new stack
   -- Executing [s@t38-faxout:7] NoOp("SIP/10-088f34e8", "###        FAXPAGES: 1") in new stack
   -- Executing [s@t38-faxout:8] NoOp("SIP/10-088f34e8", "###      FAXBITRATE: 9600") in new stack
   -- Executing [s@t38-faxout:9] NoOp("SIP/10-088f34e8", "###   FAXRESOLUTION: 3850") in new stack
   
In all four settings the fax transmissions is a success, even with this ERROR/WARNING messages
By: Kevin P. Fleming (kpfleming) 2009-10-01 07:33:00

Sorry for the delay in updates; I was on a two-week business trip and am just getting caught up.

I've attached a completely new patch, that takes a different approach to solving this problem. Instead of trying to set hardcoded minimum/maximum values for datagram sizes in the UDPTL stack, this patch adds the ability to override the remote endpoint's T38FaxMaxDatagram value on a global or per-peer/user basis in sip.conf, with any value you wish to use. The default is still to honor the value that the remote endpoint supplies, but it can be overridden to solve problems like you are experiencing.

Please give this patch a try (it's against the SVN 1.6.0 branch, I can supply versions against other branches if needed). Thanks!
By: Scott Johnson (globalnetinc) 2009-10-01 09:43:18

I will test today.
By: Scott Johnson (globalnetinc) 2009-10-01 12:02:31

Building and testing now.  Please take a look at the trace.  I beleive the root of the problem is deeper.  It appears as though the T.38 capablities are not being  parsed or interperated correctly.
By: Scott Johnson (globalnetinc) 2009-10-01 12:23:17

cannot run this as described.  when you put.

t38pt_udptl = yes,fec,maxdatagram=400

In the sip.conf file it is no longer parsed correctly.  You get these errors

[Oct  1 11:16:54] ERROR[12070]: chan_sip.c:21843 build_peer: srvlookup failed for host: dynamic, on peer 4065873088, removing peer
[Oct  1 11:16:54] WARNING[12070]: acl.c:376 ast_get_ip_or_srv: Unable to lookup 'dynamic'
[Oct  1 11:16:54] ERROR[12070]: chan_sip.c:21843 build_peer: srvlookup failed for host: dynamic, on peer 4065873078, removing peer
[Oct  1 11:16:54] WARNING[12070]: acl.c:376 ast_get_ip_or_srv: Unable to lookup 'dynamic'
[Oct  1 11:16:54] ERROR[12070]: chan_sip.c:21843 build_peer: srvlookup failed for host: dynamic, on peer 4065868232, removing peer
[Oct  1 11:16:54] WARNING[12070]: acl.c:376 ast_get_ip_or_srv: Unable to lookup 'dynamic'
[Oct  1 11:16:54] ERROR[12070]: chan_sip.c:21843 build_peer: srvlookup failed for host: dynamic, on peer 4065864717, removing peer
[Oct  1 11:16:54] WARNING[12070]: acl.c:376 ast_get_ip_or_srv: Unable to lookup 'dynamic'
[Oct  1 11:16:54] ERROR[12070]: chan_sip.c:21843 build_peer: srvlookup failed for host: dynamic, on peer 4062844326, removing peer
[Oct  1 11:16:54] WARNING[12070]: acl.c:376 ast_get_ip_or_srv: Unable to lookup 'dynamic'
[Oct  1 11:16:54] ERROR[12070]: chan_sip.c:21843 build_peer: srvlookup failed for host: dynamic, on peer 4062827668, removing peer
[Oct  1 11:16:54] WARNING[12070]: acl.c:376 ast_get_ip_or_srv: Unable to lookup 'dynamic'
[Oct  1 11:16:54] ERROR[12070]: chan_sip.c:21843 build_peer: srvlookup failed for host: dynamic, on peer 4067717174, removing peer
[Oct  1 11:16:54] WARNING[12070]: acl.c:376 ast_get_ip_or_srv: Unable to lookup 'dynamic'
[Oct  1 11:16:54] ERROR[12070]: chan_sip.c:21843 build_peer: srvlookup failed for host: dynamic, on peer 4063884554, removing peer
[Oct  1 11:16:54] WARNING[12070]: acl.c:376 ast_get_ip_or_srv: Unable to lookup 'dynamic'
[Oct  1 11:16:54] ERROR[12070]: chan_sip.c:21843 build_peer: srvlookup failed for host: dynamic, on peer 4063247307, removing peer
By: Scott Johnson (globalnetinc) 2009-10-01 12:24:24

The error is caused by adding the maxdatagram=400 at the end.
By: Scott Johnson (globalnetinc) 2009-10-01 15:36:50

cannot get any sip trunking to work with:

SVN-branch-1.6.0-r221488

app_dial.c:1499 dial_exec_full: Unable to create channel of type 'SIP' (cause 20 - Unknown)
By: Kevin P. Fleming (kpfleming) 2009-10-01 15:38:20

That is correct; chan_sip in the 1.6 branches was broken, and 1.6.0 was just fixed. I'm retesting the patch I supplied, hang on for a few minutes.
By: Kevin P. Fleming (kpfleming) 2009-10-01 15:43:03

I've attached a slightly revised version of the patch, that includes output of the selected EC mode and MaxDatagram value (if any) in 'sip show settings' and 'sip show peer'.
By: Scott Johnson (globalnetinc) 2009-10-01 16:12:08

I believe the error above is unrelated but in the SVN branch no dynamic host types work correctly on a reload.  I have attached a working fax trace from 1.6.0.10 and failed one from 1.6.0.15
By: Kevin P. Fleming (kpfleming) 2009-10-01 16:23:53

I'm not sure what you are providing me; I don't need a FAX trace from 1.6.0.15, as we know it will fail in your configuration. The patch I supplied will allow you to override the bogus T38FaxMaxDatagram value that the media gateway is sending you without having to edit any code.

Yes, the SVN 1.6.0 branch was broken, but should now be fixed. If it is not fixed, is there any chance you get on IRC (#asterisk-dev on FreeNode) so we can talk about this in realtime?
By: Scott Johnson (globalnetinc) 2009-10-01 19:55:11

okay I will pull the SVN version now.  I tried the IRC and it wants to IDent my system.  I allowed through the firewall but still fails.
By: Scott Johnson (globalnetinc) 2009-10-01 20:20:22

failed pcap for fax is attached.
By: Kevin P. Fleming (kpfleming) 2009-10-02 07:46:46

You did not include any information as to how you changed your configuration to take advantage of the override ability provided by the patch, so I don't really have any way to understand why (or how) your failure occurred.

In spite of that, I've verified that the patch does in fact allow the problem to be solved, by connecting Asterisk to another system that reports '72' for T38FaxMaxDatagram, reproducing the buffer overflow/data loss errors, and then setting 't38pt_udptl=yes,maxdatagram=400' for that peer in sip.conf. When that is done, the FAX goes through perfectly. I'm going to commit the patch to trunk and the 1.6 branches now.
By: Scott Johnson (globalnetinc) 2009-10-02 12:10:06

It may fix that problem but does not allow my fax to go through.


[4065877430]
qualify=60000
ignoresdpversion=yes
nat=yes
sendrpid=yes
usereqphone=yes
context=from-inside
call-limit=1
canreinvite=yes
g726nonstandard=no
host=dynamic
trustrpid=no
subscribecontext=local-extensions
dtmfmode=rfc2833
t38pt_udptl=yes,redundancy,maxdatagram=400
type=friend
disallow=all
allow=g726
allow=g726aal2
allow=ulaw
By: Kevin P. Fleming (kpfleming) 2009-10-02 13:42:12

Can you confirm (via the Asterisk console) that this sip.conf peer/user definition was actually used for the call in question? Unfortunately a packet capture does not really do us much good here, as we need to know how Asterisk reacted to the SIP messages it received. As before, the best thing to upload is a console log produced with 'core set verbose 10', 'core set debug 10' and 'sip set debug on' so that we can see all the Asterisk output.
By: Scott Johnson (globalnetinc) 2009-10-02 16:35:21

Yep.  It will get you 2 things. A complete pcap of all parites using 1.6.1.0 and all of the above mentioned info on a working fax call and then the same on the failed call.  I get to do these things late at night as this system is in production.
By: Scott Johnson (globalnetinc) 2009-10-04 18:00:59

I did not see a check in of the code for the other branches.  attached are 2 traces.  one is fromn 1.6.1.0 which works.  the fax goes through and is correct.  the other is from 1.6.0-svn current code.  it fails.  it has all of the info requested pluse a pcap file of the data sent 2 and from all parties involved in the fax.
By: Kevin P. Fleming (kpfleming) 2009-10-05 14:24:58

The patch has not been committed to any branches yet. Once again, I do not need traces from working versions, you've supplied plenty of them and the code for old versions of Asterisk has not changed, so producing them and uploading them is not really a good use of your time.
By: Digium Subversion (svnbot) 2009-10-05 14:48:11

Repository: asterisk
Revision: 222110

U   trunk/UPGRADE.txt
U   trunk/channels/chan_sip.c
U   trunk/configs/sip.conf.sample
U   trunk/configs/udptl.conf.sample
U   trunk/main/udptl.c

------------------------------------------------------------------------
r222110 | kpfleming | 2009-10-05 14:48:10 -0500 (Mon, 05 Oct 2009) | 25 lines

Allow non-compliant T.38 endpoints to be supportable via configuration option.

Many T.38 endpoints incorrectly send the maximum IFP frame size they can accept
as the T38FaxMaxDatagram value in their SDP, when in fact this value is
supposed to be the maximum UDPTL payload size (datagram size) they can accept.
If the value they supply is small enough (a commonly supplied value is '72'),
T.38 UDPTL transmissions will likely fail completely because the UDPTL packets
will not have enough room for a primary IFP frame and the redundancy used for
error correction. If this occurs, the Asterisk UDPTL stack will emit log messages
warning that data loss may occur, and that the value may need to be overridden.

This patch extends the 't38pt_udptl' configuration option in sip.conf to allow
the administrator to override the value supplied by the remote endpoint and
supply a value that allows T.38 FAX transmissions to be successful with that
endpoint. In addition, in any SIP call where the override takes effect, a debug
message will be printed to that effect. This patch also removes the
T38FaxMaxDatagram configuration option from udptl.conf.sample, since it has not
actually had any effect for a number of releases.

In addition, this patch cleans up the T.38 documentation in sip.conf.sample
(which incorrectly documented that T.38 support was passthrough only).

(issue ASTERISK-14531)
Reported by: globalnetinc

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=222110
By: Digium Subversion (svnbot) 2009-10-05 14:52:16

Repository: asterisk
Revision: 222111

_U  branches/1.6.0/
U   branches/1.6.0/UPGRADE.txt
U   branches/1.6.0/channels/chan_sip.c
U   branches/1.6.0/configs/sip.conf.sample
U   branches/1.6.0/configs/udptl.conf.sample
U   branches/1.6.0/main/udptl.c

------------------------------------------------------------------------
r222111 | kpfleming | 2009-10-05 14:52:15 -0500 (Mon, 05 Oct 2009) | 32 lines

Recorded merge of revisions 222110 via svnmerge from
https://origsvn.digium.com/svn/asterisk/trunk

........
 r222110 | kpfleming | 2009-10-05 14:45:00 -0500 (Mon, 05 Oct 2009) | 25 lines
 
 Allow non-compliant T.38 endpoints to be supportable via configuration option.
 
 Many T.38 endpoints incorrectly send the maximum IFP frame size they can accept
 as the T38FaxMaxDatagram value in their SDP, when in fact this value is
 supposed to be the maximum UDPTL payload size (datagram size) they can accept.
 If the value they supply is small enough (a commonly supplied value is '72'),
 T.38 UDPTL transmissions will likely fail completely because the UDPTL packets
 will not have enough room for a primary IFP frame and the redundancy used for
 error correction. If this occurs, the Asterisk UDPTL stack will emit log messages
 warning that data loss may occur, and that the value may need to be overridden.
 
 This patch extends the 't38pt_udptl' configuration option in sip.conf to allow
 the administrator to override the value supplied by the remote endpoint and
 supply a value that allows T.38 FAX transmissions to be successful with that
 endpoint. In addition, in any SIP call where the override takes effect, a debug
 message will be printed to that effect. This patch also removes the
 T38FaxMaxDatagram configuration option from udptl.conf.sample, since it has not
 actually had any effect for a number of releases.
 
 In addition, this patch cleans up the T.38 documentation in sip.conf.sample
 (which incorrectly documented that T.38 support was passthrough only).
 
 (issue ASTERISK-14531)
 Reported by: globalnetinc
........

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=222111
By: Digium Subversion (svnbot) 2009-10-05 14:56:29

Repository: asterisk
Revision: 222112

_U  branches/1.6.1/
U   branches/1.6.1/UPGRADE.txt
U   branches/1.6.1/channels/chan_sip.c
U   branches/1.6.1/configs/sip.conf.sample
U   branches/1.6.1/configs/udptl.conf.sample
U   branches/1.6.1/main/udptl.c

------------------------------------------------------------------------
r222112 | kpfleming | 2009-10-05 14:56:28 -0500 (Mon, 05 Oct 2009) | 32 lines

Merged revisions 222110 via svnmerge from
https://origsvn.digium.com/svn/asterisk/trunk

........
 r222110 | kpfleming | 2009-10-05 14:45:00 -0500 (Mon, 05 Oct 2009) | 25 lines
 
 Allow non-compliant T.38 endpoints to be supportable via configuration option.
 
 Many T.38 endpoints incorrectly send the maximum IFP frame size they can accept
 as the T38FaxMaxDatagram value in their SDP, when in fact this value is
 supposed to be the maximum UDPTL payload size (datagram size) they can accept.
 If the value they supply is small enough (a commonly supplied value is '72'),
 T.38 UDPTL transmissions will likely fail completely because the UDPTL packets
 will not have enough room for a primary IFP frame and the redundancy used for
 error correction. If this occurs, the Asterisk UDPTL stack will emit log messages
 warning that data loss may occur, and that the value may need to be overridden.
 
 This patch extends the 't38pt_udptl' configuration option in sip.conf to allow
 the administrator to override the value supplied by the remote endpoint and
 supply a value that allows T.38 FAX transmissions to be successful with that
 endpoint. In addition, in any SIP call where the override takes effect, a debug
 message will be printed to that effect. This patch also removes the
 T38FaxMaxDatagram configuration option from udptl.conf.sample, since it has not
 actually had any effect for a number of releases.
 
 In addition, this patch cleans up the T.38 documentation in sip.conf.sample
 (which incorrectly documented that T.38 support was passthrough only).
 
 (issue ASTERISK-14531)
 Reported by: globalnetinc
........

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=222112
By: Digium Subversion (svnbot) 2009-10-05 14:59:32

Repository: asterisk
Revision: 222113

_U  branches/1.6.2/
U   branches/1.6.2/UPGRADE.txt
U   branches/1.6.2/channels/chan_sip.c
U   branches/1.6.2/configs/sip.conf.sample
U   branches/1.6.2/configs/udptl.conf.sample
U   branches/1.6.2/main/udptl.c

------------------------------------------------------------------------
r222113 | kpfleming | 2009-10-05 14:59:32 -0500 (Mon, 05 Oct 2009) | 32 lines

Merged revisions 222110 via svnmerge from
https://origsvn.digium.com/svn/asterisk/trunk

........
 r222110 | kpfleming | 2009-10-05 14:45:00 -0500 (Mon, 05 Oct 2009) | 25 lines
 
 Allow non-compliant T.38 endpoints to be supportable via configuration option.
 
 Many T.38 endpoints incorrectly send the maximum IFP frame size they can accept
 as the T38FaxMaxDatagram value in their SDP, when in fact this value is
 supposed to be the maximum UDPTL payload size (datagram size) they can accept.
 If the value they supply is small enough (a commonly supplied value is '72'),
 T.38 UDPTL transmissions will likely fail completely because the UDPTL packets
 will not have enough room for a primary IFP frame and the redundancy used for
 error correction. If this occurs, the Asterisk UDPTL stack will emit log messages
 warning that data loss may occur, and that the value may need to be overridden.
 
 This patch extends the 't38pt_udptl' configuration option in sip.conf to allow
 the administrator to override the value supplied by the remote endpoint and
 supply a value that allows T.38 FAX transmissions to be successful with that
 endpoint. In addition, in any SIP call where the override takes effect, a debug
 message will be printed to that effect. This patch also removes the
 T38FaxMaxDatagram configuration option from udptl.conf.sample, since it has not
 actually had any effect for a number of releases.
 
 In addition, this patch cleans up the T.38 documentation in sip.conf.sample
 (which incorrectly documented that T.38 support was passthrough only).
 
 (issue ASTERISK-14531)
 Reported by: globalnetinc
........

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=222113
By: Kevin P. Fleming (kpfleming) 2009-10-05 15:04:54

It's apparent I've not been specific enough with my requests for how to generate the log information I need, so I'll try again. At this point, the patch has been committed to all the 1.6.x branches and trunk, so you will not need any patches to try this. Please follow these steps, in order:

1) Update to the latest 1.6.0 SVN branch code, with no patches applied.
2) Edit /etc/asterisk/logger.conf, and add the line below:

digium => notice,warning,error,verbose,debug

3) Start Asterisk.
4) Type 'core set verbose 10'.
5) Type 'core set debug 10'.
6) Type 'sip set debug on'.
7) Type 'sip show peer myfax', and capture the output of that command (it will not be sent to the log files).
8) Type 'sip show peer 4065877430', and capture the output of that command (it will not be sent to the log files).
9) Place the same FAX test call from the '4065877430' peer to 'myfax' as you did previously.
10) Once the call is complete, type 'core stop now'.
11) Upload the /var/log/asterisk/digium log file, along with the text captures from steps 7 and 8. There is no need for a packet capture.

Thanks!
By: Scott Johnson (globalnetinc) 2009-10-05 15:27:36

Sorry but that is what I did short of the sip show peer.  I will do this again.
By: Scott Johnson (globalnetinc) 2009-10-05 16:13:36

I just used the currect 1.6.1-SVN.
Asterisk SVN-branch-1.6.1-r222112

now everything works.  No changes in the sip.conf just applied current code.
By: Scott Johnson (globalnetinc) 2009-10-05 16:49:21

This only works with
t38pt_udptl=yes,redundancy,maxdatagram=400

thne though the sip header is:
<--- SIP read from UDP://216.166.168.17:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 216.166.168.6:5060;branch=z9hG4bK294d6925;rport
From: "unknown" <sip:unknown@216.166.168.6>;tag=as2ac118b6
To: <sip:216.166.168.17>
Call-ID: 4525aeae092f0b53423d2c3439a39756@216.166.168.6
CSeq: 102 OPTIONS
Contact: <sip:IPFax@216.166.168.17:5060>
User-Agent: Net Satisfaxtion/IP_FAX-8.5.4716.620
Content-Type: application/sdp
Content-Length: 287

v=0
o=IPFax 1254778879 1254778879 IN IP4 216.166.168.17
s=SIP Fax Call
t=0 0
m=image 0 udptl t38
c=IN IP4 216.166.168.17
a=T38FaxVersion:0
a=T38MaxBitRate:14400
a=T38FaxRateManagement:transferredTCF
a=T38FaxMaxBuffer:200
a=T38FaxMaxDatagram:72
a=T38FaxUdpEC:t38UDPRedundancy


the peer shows as
 T.38 support : Yes
 T.38 EC mode : FEC
 T.38 MaxDtgrm: -1

if you just use t38pt_udptl=yes and you get these errors

[Oct  5 15:45:47] NOTICE[3392]: udptl.c:1010 ast_udptl_write: UDPTL Transmission error to 216.166.168.17:49154: Message too long
[Oct  5 15:45:47] WARNING[3392]: udptl.c:997 ast_udptl_write: UDPTL asked to send 51 bytes of IFP when far end only prepared to accept 12 bytes; da.
[Oct  5 15:45:47] ERROR[3392]: udptl.c:291 encode_open_type: Buffer overflow detected (53 + 57 > 72)
[Oct  5 15:45:47] NOTICE[3392]: udptl.c:1010 ast_udptl_write: UDPTL Transmission error to 216.166.168.17:49154: Message too long
By: Scott Johnson (globalnetinc) 2009-10-05 17:03:15

unless it is hard set in the sip.conf the udptl code treats them all as
 T.38 support : Yes
 T.38 EC mode : FEC
 T.38 MaxDtgrm: -1

it does not read the info from the sip/sdp header.  If you set them all then the fax goes through.  I have now tried 6 different sip providers/fax servers.  The all work if they are set by hand.
By: Kevin P. Fleming (kpfleming) 2009-10-05 18:07:53

You are misunderstanding what the changes do; if you do *not* set 'maxdatagram' in sip.conf for a peer, then the normal SIP/SDP processing is done, and the T38FaxMaxDatagram value provided by the peer is respected. That is why when the peer sends you 'T38FaxMaxDatagram: 72' you will see buffer overrun errors from udptl.c, and it is also why the errors from udptl.c show '72' as the buffer size. When you do a 'sip show peer' and it says "T.38 MaxDtgrm: -1" that *only* means that you have not chosen to override the value provided by the peer; 'sip show peer' does not show the 'info from the sip/sdp header', it shows peer configuration information, not per-call information.

If all your SIP providers/FAX servers are sending very small T38FaxMaxDatagram values, then yes, you'll need to set 'maxdatagram' in sip.conf (which you can do in the [global] section if you like, then it will automatically apply to all peers). This is necessary because for T.38 recommendation compliant endpoints, when they tell us their MaxDatagram value, we *must* respect it, otherwise we risk sending them overly large packets that could cause transmission failures or crashes. In spite of this, there are many broken endpoints that send incorrect values for this parameter, and so I've provided a workaround. Using this workaround means your system *might* send them a packet that is too large for them to accept (depending on how high you set 'maxdatagram'), but there is nothing that you or I can do about that, because they did not properly tell you what they are able to accept.

I'm glad your FAXes are now working properly, and I appreciate your willingness to stick with this and provide test results; many of these problems are very hard (or impossible) for us reproduce in our offices/labs, so we need real-world testers to provide feedback. Thanks!
By: Kevin P. Fleming (kpfleming) 2009-10-05 18:11:04

Just another comment, if you look at these lines from your log:

[Oct  5 14:56:41] DEBUG[32247] chan_sip.c: Overriding T38FaxMaxDatagram '72' with '400'
[Oct  5 14:56:41] DEBUG[32247] chan_sip.c: FaxMaxDatagram: 400

You can see exactly how the override works; the peer sent you a re-INVITE with 'T38FaxMaxDatagram: 72', but because you've configured an override to '400', the value was overridden and processing continued as if the peer had sent '400' in their re-INVITE.