Very strange data loss with jsm driver

Very strange data loss with jsm driver

[Lennart Sorensen]

I discovered a strange situation where the jsm driver discards the
majority of transmit data.

I have two text files.

The first file consists of 9100 lines of:
0123456789<newline>
Total 100100 bytes.

The second file consists of 100 lines of:
01234567890123456789.....0123456789<newline> (1000 character line)
Total 100100 bytes.

The first file transmits instantly, with the receiving end getting
approximately 100 bytes of the data.

The second file sends in about 1 minute and 40 seconds at 9600 baud
(the speed doesn't affect the behaviour in any noticeable way) as one
would expect, and the other end sees all the data.

The trigger point appears to be lines of up to 14 bytes, followed by
a newline.  With 15 bytes or more per line it seems to be OK.

Anyone got a clue?

I was testing on 3.0.0.  Same on 2.6.32.

3.0.0 unfortunately no longer has port statistics on the jsm driver in
/proc/tty/driver/jsm making it hard to see what the driver believes is
going on, it seems 2.6.37 broke that with some serial cleanup.
I am cleaning up a patch to fix that.

-- 
Len Sorensen

Re: Very strange data loss with jsm driver

[Alan Cox]

> The trigger point appears to be lines of up to 14 bytes, followed by
> a newline.  With 15 bytes or more per line it seems to be OK.
> 
> Anyone got a clue?

FIFO size perhaps - and some kind of missed wakeup or tx handling bug ?

Re: Very strange data loss with jsm driver

[Lennart Sorensen]

On Fri, Jul 29, 2011 at 05:27:36PM +0100, Alan Cox wrote:
> > The trigger point appears to be lines of up to 14 bytes, followed by
> > a newline.  With 15 bytes or more per line it seems to be OK.
> > 
> > Anyone got a clue?
> 
> FIFO size perhaps - and some kind of missed wakeup or tx handling bug ?

FIFO size is 64bytes, so that doesn't immediately sound related.

The thing I find weird is that it thinks everything was sent right away.

Also why should the newline have anything to do with it?  If you send
100100 bytes should it matter where the newlines are unless the tty
layer or the driver is interpreting the newlines for some reason.

-- 
Len Sorensen

Re: Very strange data loss with jsm driver

[Lennart Sorensen]

On Fri, Jul 29, 2011 at 12:53:42PM -0400, Lennart Sorensen wrote:
> On Fri, Jul 29, 2011 at 05:27:36PM +0100, Alan Cox wrote:
> > > The trigger point appears to be lines of up to 14 bytes, followed by
> > > a newline.  With 15 bytes or more per line it seems to be OK.
> > > 
> > > Anyone got a clue?
> > 
> > FIFO size perhaps - and some kind of missed wakeup or tx handling bug ?
> 
> FIFO size is 64bytes, so that doesn't immediately sound related.
> 
> The thing I find weird is that it thinks everything was sent right away.
> 
> Also why should the newline have anything to do with it?  If you send
> 100100 bytes should it matter where the newlines are unless the tty
> layer or the driver is interpreting the newlines for some reason.

Same breakage on 2.6.18.  I suspect this has always been broken.

Hmm.

I noticed fifosize in the uart_port info is set to 16, even though the
fifo size is actually 64 bytes as all actual driver bits know.  What is
fifosize actually used for?

-- 
Len Sorensen

Re: Very strange data loss with jsm driver

[Lennart Sorensen]

On Fri, Jul 29, 2011 at 07:14:42PM +0100, Alan Cox wrote:
> > I noticed fifosize in the uart_port info is set to 16, even though the
> > fifo size is actually 64 bytes as all actual driver bits know.  What is
> > fifosize actually used for?
> 
> Only within the driver. The generic code merely knows how it as a
> configuration property but doesn't use it.

Well the driver certainly never uses that value.  I guess setserial can
poke at it, but it won't do anything with it.

I wonder how I should go about trying to figure out why the driver acts
so strangely with this particular input pattern.

It seems it can't be the tty layer, since other serial drivers seem to
work fine.  It has to be the jsm.

-- 
Len Sorensen

Re: Very strange data loss with jsm driver

[Alan Cox]

> I noticed fifosize in the uart_port info is set to 16, even though the
> fifo size is actually 64 bytes as all actual driver bits know.  What is
> fifosize actually used for?

Only within the driver. The generic code merely knows how it as a
configuration property but doesn't use it.

Alan

Re: Very strange data loss with jsm driver

[Breno Leitao]

On 07/29/2011 03:13 PM, Lennart Sorensen wrote:
>
>  It seems it can't be the tty layer, since other serial drivers seem to
>  work fine. It has to be the jsm.
Well, I finally tested it over here, and what I found is:

If the line has a \r among the first 16 bytes, then the information
is TXed immediately. If there is no \r in the first 16 bytes, then the
information seems to be buffered.

So, it seems that that the patch should ask the driver to TX the
information when we receive a \r or when the buffer is full. Does it
make sense to you ?

Thanks

Re: Very strange data loss with jsm driver

[Lennart Sorensen]

On Tue, Aug 02, 2011 at 11:17:52AM -0300, Breno Leitao wrote:
> Well, I finally tested it over here, and what I found is:
> 
> If the line has a \r among the first 16 bytes, then the information
> is TXed immediately. If there is no \r in the first 16 bytes, then the
> information seems to be buffered.

Where in the driver is this happening?

> So, it seems that that the patch should ask the driver to TX the
> information when we receive a \r or when the buffer is full. Does it
> make sense to you ?

Not sure.  I just wonder why the data is disappearing rather than getting
buffered somewhere.  Clearly the other serial drivers are doing that
successfully.

I don't even know why the driver should care about the contents at all.
Just send data when it is ready.

-- 
Len Sorensen

Re: Very strange data loss with jsm driver

[Lennart Sorensen]

On Tue, Aug 02, 2011 at 10:22:25AM -0400, Lennart Sorensen wrote:
> On Tue, Aug 02, 2011 at 11:17:52AM -0300, Breno Leitao wrote:
> > Well, I finally tested it over here, and what I found is:
> > 
> > If the line has a \r among the first 16 bytes, then the information
> > is TXed immediately. If there is no \r in the first 16 bytes, then the
> > information seems to be buffered.
> 
> Where in the driver is this happening?
> 
> > So, it seems that that the patch should ask the driver to TX the
> > information when we receive a \r or when the buffer is full. Does it
> > make sense to you ?
> 
> Not sure.  I just wonder why the data is disappearing rather than getting
> buffered somewhere.  Clearly the other serial drivers are doing that
> successfully.
> 
> I don't even know why the driver should care about the contents at all.
> Just send data when it is ready.

Also, do you have any idea how to fix the statistics that 2.6.37 broke?
/proc/tty/driver/jsm used to show TX/RX and such, and that stopped
working.  I managed to fix it on Debian's 2.6.32 kernel which has some
2.6.37 serial stuff backported, but the same fix didn't work on 3.0.0.

-- 
Len Sorensen

Re: Very strange data loss with jsm driver

[Breno Leitao]

On 08/02/2011 11:22 AM, Lennart Sorensen wrote:
>  On Tue, Aug 02, 2011 at 11:17:52AM -0300, Breno Leitao wrote:
> > Well, I finally tested it over here, and what I found is:
> >
> > If the line has a \r among the first 16 bytes, then the information
> > is TXed immediately. If there is no \r in the first 16 bytes, then the
> > information seems to be buffered.
>
>  Where in the driver is this happening?
Well, I just found it doing some test cases.

Enabling the driver debug, I found that ->intr is not being called on
the "incorrect" case.

This is the diff of the logs:

  jsm 0005:02:00.0: finish
  jsm 0005:02:00.0: start
  jsm 0005:02:00.0: finish
-jsm 0005:02:00.0: drivers/tty/serial/jsm/jsm_neo.c:1131 uart_poll: 301
-jsm 0005:02:00.0: drivers/tty/serial/jsm/jsm_neo.c:1161 port: 0 type: 3
-jsm 0005:02:00.0: drivers/tty/serial/jsm/jsm_neo.c:750 isr: 2
-jsm 0005:02:00.0: MOD_STAT: sending to parse_modem_sigs
-jsm 0005:02:00.0: neo_parse_modem: port: 0 msignals: 0
-jsm 0005:02:00.0: Port: 0 DTR: 0 RTS: 0 CTS: 0 DSR: 0 RI: 0 CD: 0
  jsm 0005:02:00.0: start
  jsm 0005:02:00.0: Close. HUPCL set, dropping DTR/RTS
  jsm 0005:02:00.0: finish
-jsm 0005:02:00.0: finish.

Anyway, I am still debugging it.

PS: I will look at the stats regression after I fix this one, ok ?

Re: Very strange data loss with jsm driver

[Lennart Sorensen]

On Tue, Aug 02, 2011 at 11:49:27AM -0300, Breno Leitao wrote:
> On 08/02/2011 11:22 AM, Lennart Sorensen wrote:
> > On Tue, Aug 02, 2011 at 11:17:52AM -0300, Breno Leitao wrote:
> >> Well, I finally tested it over here, and what I found is:
> >>
> >> If the line has a \r among the first 16 bytes, then the information
> >> is TXed immediately. If there is no \r in the first 16 bytes, then the
> >> information seems to be buffered.
> >
> > Where in the driver is this happening?
> Well, I just found it doing some test cases.
> 
> Enabling the driver debug, I found that ->intr is not being called on
> the "incorrect" case.
> 
> This is the diff of the logs:
> 
>  jsm 0005:02:00.0: finish
>  jsm 0005:02:00.0: start
>  jsm 0005:02:00.0: finish
> -jsm 0005:02:00.0: drivers/tty/serial/jsm/jsm_neo.c:1131 uart_poll: 301
> -jsm 0005:02:00.0: drivers/tty/serial/jsm/jsm_neo.c:1161 port: 0 type: 3
> -jsm 0005:02:00.0: drivers/tty/serial/jsm/jsm_neo.c:750 isr: 2
> -jsm 0005:02:00.0: MOD_STAT: sending to parse_modem_sigs
> -jsm 0005:02:00.0: neo_parse_modem: port: 0 msignals: 0
> -jsm 0005:02:00.0: Port: 0 DTR: 0 RTS: 0 CTS: 0 DSR: 0 RI: 0 CD: 0
>  jsm 0005:02:00.0: start
>  jsm 0005:02:00.0: Close. HUPCL set, dropping DTR/RTS
>  jsm 0005:02:00.0: finish
> -jsm 0005:02:00.0: finish.
> 
> Anyway, I am still debugging it.
> 
> PS: I will look at the stats regression after I fix this one, ok ?

Sure.  I originally thought it might be related, but once I found 2.6.18
had the problem too, I no longer think so.

However having the statistics may very well be helpful while debuging,
at least I thought so.  being able to see how many characters the driver
thinks it has sent versus how many user space asked to send and how many
the receiver has seen might be handy.

-- 
Len Sorensen