[asterisk-users] Still on spandsp/app_fax and T.38

Wed Feb 17 13:27:17 CST 2010

----- "Vinícius Fontes" <vinicius at canall.com.br> escreveu:

> ----- "Steve Underwood" <steveu at coppice.org> escreveu:
> 
> > Hi Vinícius,
> > 
> > Don't post big things, like wireshark traces, to a mailing list.
> They
> > 
> > are likely to ban you.
> > 
> > The first two calls in your wireshark log decode to the attached
> > images. 
> > There were no lost packets. The wireshark logs contains exactly
> what
> > the 
> > far end sent, and it was not good. The first fax page has 12 bad
> pixel
> > 
> > rows. This page was accepted, as minor defects like this are
> normally
> > 
> > accepted. The second fax starts out OK, then then just falls apart.
> I
> > 
> > think the receive modem in that gateway probably lost sync. The data
> 
> > looks like complete rubbish beyond the part that decodes to
> something
> > 
> > sensible.
> > 
> > The system you are trying to interwork with seems to have serious 
> > issues. It can be difficult to get providers to sort out T.38
> issues,
> > as 
> > many of them have very little understanding of the systems they
> have.
> > 
> > Even big carriers can be very unresponsive, because they just don't
> > know 
> > what to do.
> > 
> > Regards,
> > Steve
> > 
> > 
> > On 02/18/2010 12:19 AM, Vinícius Fontes wrote:
> > >> Can you try the attached version of spandsp with the T.38
> gateway
> > you
> > >>
> > >> are using? It behaves a lot more like FFA, and I want to see if
> > this
> > >> makes the gateway behave properly. If it does I will have to
> > consider
> > >>
> > >> some more permanent changes to spandsp to increase its tolerance
> > of
> > >> yet
> > >> another broken T.38 implementation. It really is depressing
> having
> > to
> > >>
> > >> work around other people's broken systems like this.
> > >>
> > >> Steve
> > >>      
> > > Hi Steve. I installed the spandsp you sent me and made some
> tests.
> > >
> > > Before proceeding, it is important to share with you what I
> noticed
> > today. Even before I installed the new spandsp lib I noticed that I
> > started to receive faxes at 9600 bps, only problem being the fax
> won't
> > get received in about 60% of the cases. I'm guessing the provider
> > changed something at their side, because I don't remember changing
> any
> > configs on Asterisk. Also important to say that it is happening to
> > both app_fax and FFA now.
> > >
> > > Anyway, I installed the spandsp you sent me and noticed no
> > difference on the behaviour. Attached to this message is a capture
> of
> > four calls. As usual, you should only consider calls from
> 5433142499
> > to 5421047008. There are four calls, detailed as follows:
> > >
> > > 1) app_fax, returned an error. Here's the CLI:
> > >
> > > [Feb 17 13:55:16]     -- Executing [5421047008 at entrada-e1:1]
> > Goto("SIP/voxip-00000010", "interno,7008,1") in new stack
> > > [Feb 17 13:55:16]     -- Goto (interno,7008,1)
> > > [Feb 17 13:55:16]     -- Executing [7008 at interno:1]
> > Goto("SIP/voxip-00000010", "macro-recebefax,s,1") in new stack
> > > [Feb 17 13:55:16]     -- Goto (macro-recebefax,s,1)
> > > [Feb 17 13:55:16]     -- Executing [s at macro-recebefax:1]
> > Set("SIP/voxip-00000010", "DB(fax/count)=92") in new stack
> > > [Feb 17 13:55:16]     -- Executing [s at macro-recebefax:2]
> > Set("SIP/voxip-00000010", "FAXCOUNT=92") in new stack
> > > [Feb 17 13:55:16]     -- Executing [s at macro-recebefax:3]
> > Set("SIP/voxip-00000010", "FAXFILE=fax-92-rx") in new stack
> > > [Feb 17 13:55:16]     -- Executing [s at macro-recebefax:4]
> > Set("SIP/voxip-00000010", "LOCALSTATIONID=5421047008") in new stack
> > > [Feb 17 13:55:16]     -- Executing [s at macro-recebefax:5]
> > ReceiveFAX("SIP/voxip-00000010",
> > "/var/spool/asterisk/fax/fax-92-rx.tif") in new stack
> > > [Feb 17 13:56:03] WARNING[3418]: app_fax.c:128 span_message:
> WARNING
> > T.30 Page did not end cleanly
> > > [Feb 17 13:56:09] WARNING[3418]: app_fax.c:178 phase_e_handler:
> > Error transmitting fax. result=40: Unexpected DCN after requested
> > retransmission.
> > > [Feb 17 13:56:09] WARNING[3418]: app_fax.c:767 transmit:
> > Transmission failed
> > > [Feb 17 13:56:09]     -- Executing [s at macro-recebefax:6]
> > NoOp("SIP/voxip-00000010", "FAXSTATUS = FAILED") in new stack
> > > [Feb 17 13:56:09]     -- Executing [s at macro-recebefax:7]
> > NoOp("SIP/voxip-00000010", "FAXERROR = Unexpected DCN after
> requested
> > retransmission") in new stack
> > > [Feb 17 13:56:09]     -- Executing [s at macro-recebefax:8]
> > NoOp("SIP/voxip-00000010", "CALLID =  5433142499 ") in new stack
> > > [Feb 17 13:56:09]     -- Executing [s at macro-recebefax:9]
> > NoOp("SIP/voxip-00000010", "FAXPAGES = ") in new stack
> > > [Feb 17 13:56:09]     -- Executing [s at macro-recebefax:10]
> > NoOp("SIP/voxip-00000010", "FAXBITRATE = ") in new stack
> > > [Feb 17 13:56:09]     -- Executing [s at macro-recebefax:11]
> > NoOp("SIP/voxip-00000010", "FAXRESOLUTION = ") in new stack
> > > [Feb 17 13:56:09]     -- Executing [s at macro-recebefax:12]
> > NoOp("SIP/voxip-00000010", "FAXMODE = T38") in new stack
> > > [Feb 17 13:56:09]     -- Executing [s at macro-recebefax:13]
> > Hangup("SIP/voxip-00000010", "") in new stack
> > > [Feb 17 13:56:09]   == Spawn extension (macro-recebefax, s, 13)
> > exited non-zero on 'SIP/voxip-00000010'
> > >
> > > 2) app_fax, received the fax succesfully. No configs changed.
> > >
> > > 3) FFA, error. All I did in order to use FFA was this:
> > >
> > > module unload app_fax.so
> > > module load res_fax.so
> > > module load res_fax_digium.so
> > >
> > > Here's the CLI when the error happened:
> > >
> > > [Feb 17 13:56:35]     -- Executing [5421047008 at entrada-e1:1]
> > Goto("SIP/voxip-00000019", "interno,7008,1") in new stack
> > > [Feb 17 13:56:35]     -- Goto (interno,7008,1)
> > > [Feb 17 13:56:35]     -- Executing [7008 at interno:1]
> > Goto("SIP/voxip-00000019", "macro-recebefax,s,1") in new stack
> > > [Feb 17 13:56:35]     -- Goto (macro-recebefax,s,1)
> > > [Feb 17 13:56:35]     -- Executing [s at macro-recebefax:1]
> > Set("SIP/voxip-00000019", "DB(fax/count)=93") in new stack
> > > [Feb 17 13:56:35]     -- Executing [s at macro-recebefax:2]
> > Set("SIP/voxip-00000019", "FAXCOUNT=93") in new stack
> > > [Feb 17 13:56:35]     -- Executing [s at macro-recebefax:3]
> > Set("SIP/voxip-00000019", "FAXFILE=fax-93-rx") in new stack
> > > [Feb 17 13:56:35]     -- Executing [s at macro-recebefax:4]
> > Set("SIP/voxip-00000019", "LOCALSTATIONID=5421047008") in new stack
> > > [Feb 17 13:56:35]     -- Executing [s at macro-recebefax:5]
> > ReceiveFAX("SIP/voxip-00000019",
> > "/var/spool/asterisk/fax/fax-93-rx.tif") in new stack
> > > [Feb 17 13:56:35]     -- Channel 'SIP/voxip-00000019' receiving
> FAX
> > '/var/spool/asterisk/fax/fax-93-rx.tif'
> > > [Feb 17 13:56:35] NOTICE[3435]: res_fax.c:712 generic_fax_exec:
> > Negotiating T.38 for receive on SIP/voxip-00000019
> > > [Feb 17 13:56:35] NOTICE[3435]: res_fax.c:779 generic_fax_exec:
> > Negotiated T.38 for receive on SIP/voxip-00000019
> > > [Feb 17 13:56:35]     -- Channel 'SIP/voxip-00000019' FAX session
> > '0' started
> > > [Feb 17 13:57:26]     -- FAX handle 0: [ 051.075619 ], entering
> > CLOSING state
> > > [Feb 17 13:57:26]     -- FAX handle 0: [ 051.165605 ], entering
> > CLOSING state
> > > [Feb 17 13:57:29]     -- Channel 'SIP/voxip-00000019' FAX session
> > '0' is complete, result: 'FAILED' (FAX_FAILURE_PARTIAL), error:
> > 'NO_ERROR', pages: 1, resolution: '204x98', transfer rate: '9600',
> > remoteSID: '5421047010'
> > > [Feb 17 13:57:29]     -- Executing [s at macro-recebefax:6]
> > NoOp("SIP/voxip-00000019", "FAXSTATUS = FAILED") in new stack
> > > [Feb 17 13:57:29]     -- Executing [s at macro-recebefax:7]
> > NoOp("SIP/voxip-00000019", "FAXERROR = NO_ERROR") in new stack
> > > [Feb 17 13:57:29]     -- Executing [s at macro-recebefax:8]
> > NoOp("SIP/voxip-00000019", "CALLID =  5433142499 5421047010") in
> new
> > stack
> > > [Feb 17 13:57:29]     -- Executing [s at macro-recebefax:9]
> > NoOp("SIP/voxip-00000019", "FAXPAGES = 1") in new stack
> > > [Feb 17 13:57:29]     -- Executing [s at macro-recebefax:10]
> > NoOp("SIP/voxip-00000019", "FAXBITRATE = 9600") in new stack
> > > [Feb 17 13:57:29]     -- Executing [s at macro-recebefax:11]
> > NoOp("SIP/voxip-00000019", "FAXRESOLUTION = 204x98") in new stack
> > > [Feb 17 13:57:29]     -- Executing [s at macro-recebefax:12]
> > NoOp("SIP/voxip-00000019", "FAXMODE = ") in new stack
> > > [Feb 17 13:57:29]     -- Executing [s at macro-recebefax:13]
> > Hangup("SIP/voxip-00000019", "") in new stack
> > > [Feb 17 13:57:29]   == Spawn extension (macro-recebefax, s, 13)
> > exited non-zero on 'SIP/voxip-00000019'
> > >
> > > 4) FFA, received successfully. Again, no change in any configs.
> > >
> > >
> > > That provider delivers a 2mbps SHDSL modem connected to a Cisco
> 1841
> > router with 2 ethernet interfaces. On the first one it's the SIP
> DID
> > dedicated service, capped to 1mbps and 15 simultaneous calls. On
> the
> > other port there is a business grade Internet access, also capped
> to
> > 1mbps. The only thing that changed form last week is that I started
> to
> > use that Internet link, but it should not interfere because the
> > provider configures QoS on both ends. I unfortunely don't
> understand
> > the T38 protocol enough to tell if there's packet loss or something
> > just looking at the capture. Could you take a look at that please?
> I
> > think that might be the cause of the sudden unreliability.
> > >
> > >
> 
> 
> Another thing I found out: with vanilla FFA, without setting any
> options, the baudrate is negotiated at 9600 and the fax may or may not
> be transmitted. But if I set the following options:
> 
> exten => s,n,Set(FAXOPT(ecm)=yes)
> exten => s,n,Set(FAXOPT(modem)=V28)
> 
> Then the transmission is negotiated at 4800bps and all transmissions
> occur perfectly. Unfortunely I didn't find a similar config on
> app_fax, so I could not test this on app_fax.
> 
> You said in another email that the provider is sending invalid
> training data. I noticed also that the provider always try to
> negotiate the baudrate on the SDP to 14400, and that is accepted by
> Asterisk. Could it be that's a buffer overflow happening? I mean, is
> it possible that the provider is trying to send data faster than
> app_fax/spandsp/Asterisk can handle?

And by V28 I of course meant V27 on that last email.