lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <m1lji4od0k.fsf@fess.ebiederm.org>
Date:	Tue, 17 Nov 2009 17:08:43 -0800
From:	ebiederm@...ssion.com (Eric W. Biederman)
To:	Oliver Neukum <oliver@...kum.org>
Cc:	Alan Cox <alan@...rguk.ukuu.org.uk>,
	Johan Hovold <jhovold@...il.com>,
	"Greg Kroah-Hartman" <gregkh@...e.de>,
	Michael Trimarchi <trimarchi@...dalf.sssup.it>,
	linux-usb@...r.kernel.org, Alan Cox <alan@...hat.com>,
	Andrew Morton <akpm@...ux-foundation.org>,
	linux-kernel@...r.kernel.org,
	Alan Stern <stern@...land.harvard.edu>
Subject: Re: [PATCH] USB: ftdi_sio: Remove tty->low_latency.

Oliver Neukum <oliver@...kum.org> writes:

> Am Dienstag, 17. November 2009 19:35:07 schrieb Eric W. Biederman:
>> Boiled down.  ftdi_chars_in_buffer is essentially
>>  priv->tx_outstanding_bytes. tx_outstanding_bytes is incremented when an
>>  urb request is sent and tx_outstanding_bytes is decremented when an urb
>>  request completes.
>> 
>> It turns out I have a moderately noisy usb line, and so I occasionally
>> get messages like:
>> 
>> ehci_hcd 0000:00:0a.1: detected XactErr len 0/7 retry 31
>> 
>> Which as best as I can tell result in the urb getting abandoned and
>> neither completed nor canceled (because we have hit the maximum
>> retry count and they still don't succeed).
>
> The URB should be finished with an error code in urb->status.
> ftdi_write_bulk_callback() does decrement the counter even in
> the error case.
>
>> Which appears to result in tx_outstanding_bytes getting stuck at
>> some positive number.
>
> Do you see this message
>
>  	if (status) {
> 		dbg("nonzero write bulk status received: %d", status);
> 		return;
> 	}
>
> if you enable debugging output?

Ok.  After a bunch of minor tweaks to the debug messages I finally have a smoking gun trace.

The highlights:

*  ftdi_write port 15, 7 bytes

*  detected XactErr len 0/7 retry 1

*  ftdi_write_bulk_callback - port 15

*  nonzero write bulk status received: -71 countback: 0

*  ftdi_chars_in_buffer - port 15 buffered: 7

We write 7 bytes, we get an error and a completion with status
-EPROTO, but no bytes have actually been transferred so actual_length
less the headers is 0.  Since we don't subtract off any bytes when we
get the completion we figure 7 bytes are actually in flight when they
are not.

Eric


Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_chars_in_buffer - port 15 buffered: 0
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_write_room - port 15
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_chars_in_buffer - port 14 buffered: 0
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_write_room - port 14
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_chars_in_buffer - port 13 buffered: 0
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_write_room - port 13
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_chars_in_buffer - port 12 buffered: 0
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_write_room - port 12
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_write port 15, 7 bytes
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: data_offset set to 0
Nov 17 16:44:35 localhost kernel: ftdi_sio ttyUSB15: ftdi_write - length = 7, data = 31 34 33 30 34 0d 0a 
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_write write returning: 7
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_chars_in_buffer - port 31 buffered: 0
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_write_room - port 31
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_chars_in_buffer - port 30 buffered: 0
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_write_room - port 30
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_chars_in_buffer - port 29 buffered: 0
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_write_room - port 29
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_chars_in_buffer - port 28 buffered: 0
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_write_room - port 28
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_chars_in_buffer - port 23 buffered: 0
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_write_room - port 23
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_chars_in_buffer - port 22 buffered: 0
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_write_room - port 22
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_chars_in_buffer - port 21 buffered: 0
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_write_room - port 21
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_chars_in_buffer - port 20 buffered: 0
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_write_room - port 20
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_chars_in_buffer - port 19 buffered: 0
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_write_room - port 19
Nov 17 16:44:35 localhost kernel: ehci_hcd 0000:00:0a.1: 9.2 detected XactErr len 0/7 retry 1
Nov 17 16:44:35 localhost kernel: ehci_hcd 0000:00:0a.1: devpath 9.2 ep4out 3strikes
Nov 17 16:44:35 localhost kernel: usb 1-9: clear tt buffer port 2, a12 ep4 t80078048
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_chars_in_buffer - port 18 buffered: 0
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_write_room - port 18
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_chars_in_buffer - port 17 buffered: 0
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_write_room - port 17
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_write_bulk_callback - port 15
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: nonzero write bulk status received: -71 countback: 0
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_chars_in_buffer - port 16 buffered: 0
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_write_room - port 16
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_chars_in_buffer - port 15 buffered: 7
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_write_room - port 15
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_chars_in_buffer - port 14 buffered: 0
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_write_room - port 14
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_chars_in_buffer - port 13 buffered: 0
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_write_room - port 13
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_chars_in_buffer - port 12 buffered: 0
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_write_room - port 12
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_chars_in_buffer - port 31 buffered: 0
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_write_room - port 31
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_chars_in_buffer - port 30 buffered: 0
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_write_room - port 30
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_chars_in_buffer - port 29 buffered: 0
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_write_room - port 29
Nov 17 16:44:35 localhost kernel: /home/ebiederm/projects/linux/linux-2.6.32-Arora/drivers/usb/serial/ftdi_sio.c: ftdi_chars_in_buffer - port 28 buffered: 0

Debugging diff attached for anyone who cares.


View attachment "usb-debug.diff2" of type "text/plain" (3211 bytes)

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ