Oliver Neukum <oliver@xxxxxxxxxx> 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.
diff --git a/drivers/char/tty_ioctl.c b/drivers/char/tty_ioctl.c
index 8e67d5c..616ec99 100644
--- a/drivers/char/tty_ioctl.c
+++ b/drivers/char/tty_ioctl.c
@@ -26,7 +26,7 @@
#include <asm/uaccess.h>
#include <asm/system.h>
-#undef TTY_DEBUG_WAIT_UNTIL_SENT
+#define TTY_DEBUG_WAIT_UNTIL_SENT
#undef DEBUG
diff --git a/drivers/usb/host/ehci-q.c b/drivers/usb/host/ehci-q.c
index 2494599..0766f1b 100644
--- a/drivers/usb/host/ehci-q.c
+++ b/drivers/usb/host/ehci-q.c
@@ -392,7 +392,7 @@ qh_completions (struct ehci_hcd *ehci, struct ehci_qh *qh)
"%s detected XactErr len %zu/%zu retry %d\n",
qtd->urb->dev->devpath,
qtd->length - QTD_LENGTH(token), qtd->length, qh->xacterrs);
-
+#if 0
/* reset the token in the qtd and the
* qh overlay (which still contains
* the qtd) so that we pick up from
@@ -407,6 +407,7 @@ qh_completions (struct ehci_hcd *ehci, struct ehci_qh *qh)
hw->hw_token = cpu_to_hc32(ehci,
token);
goto retry_xacterr;
+#endif
}
stopped = 1;
diff --git a/drivers/usb/serial/Makefile b/drivers/usb/serial/Makefile
index 66619be..194a1b7 100644
--- a/drivers/usb/serial/Makefile
+++ b/drivers/usb/serial/Makefile
@@ -55,4 +55,3 @@ obj-$(CONFIG_USB_SERIAL_TI) += ti_usb_3410_5052.o
obj-$(CONFIG_USB_SERIAL_VISOR) += visor.o
obj-$(CONFIG_USB_SERIAL_WHITEHEAT) += whiteheat.o
obj-$(CONFIG_USB_SERIAL_XIRCOM) += keyspan_pda.o
-
diff --git a/drivers/usb/serial/ftdi_sio.c b/drivers/usb/serial/ftdi_sio.c
index 9c60d6d..f9065a4 100644
--- a/drivers/usb/serial/ftdi_sio.c
+++ b/drivers/usb/serial/ftdi_sio.c
@@ -1949,7 +1949,8 @@ static void ftdi_write_bulk_callback(struct urb *urb)
spin_unlock_irqrestore(&priv->tx_lock, flags);
if (status) {
- dbg("nonzero write bulk status received: %d", status);
+ dbg("nonzero write bulk status received: %d countback: %lu",
+ status, countback);
return;
}
@@ -1988,11 +1989,10 @@ static int ftdi_chars_in_buffer(struct tty_struct *tty)
int buffered;
unsigned long flags;
- dbg("%s - port %d", __func__, port->number);
-
spin_lock_irqsave(&priv->tx_lock, flags);
buffered = (int)priv->tx_outstanding_bytes;
spin_unlock_irqrestore(&priv->tx_lock, flags);
+ dbg("%s - port %d buffered: %d", __func__, port->number, buffered);
if (buffered < 0) {
dev_err(&port->dev, "%s outstanding tx bytes is negative!\n",
__func__);
@@ -2010,7 +2010,9 @@ static int ftdi_process_packet(struct tty_struct *tty,
char flag;
char *ch;
+#if 0
dbg("%s - port %d", __func__, port->number);
+#endif
if (len < 2) {
dbg("malformed packet");
@@ -2096,7 +2098,9 @@ static void ftdi_read_bulk_callback(struct urb *urb)
struct usb_serial_port *port = urb->context;
unsigned long flags;
+#if 0
dbg("%s - port %d", __func__, port->number);
+#endif
if (urb->status) {
dbg("%s - nonzero read bulk status received: %d",
@@ -2104,8 +2108,10 @@ static void ftdi_read_bulk_callback(struct urb *urb)
return;
}
+#if 0
usb_serial_debug_data(debug, &port->dev, __func__,
urb->actual_length, urb->transfer_buffer);
+#endif
ftdi_process_read(port);
spin_lock_irqsave(&port->lock, flags);
diff --git a/include/linux/usb.h b/include/linux/usb.h
