[REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Matthew Garrett]

gobi_loader writes firmware to gobi USB devices (qcserial) via the USB 
serial layer by writing it a megabyte at a time (matching the Windows 
driver behaviour). Commit 8e8dce065088833fc418bfa5fbf035cb0726c04c 
breaks it - strace shows the write simply hanging. ssyrq-t says the 
backtrace is:

Jan 17 15:37:37 localhost kernel: Call Trace:
Jan 17 15:37:37 localhost kernel: [<ffffffff8128986c>] n_tty_write+0x2da/0x351
Jan 17 15:37:37 localhost kernel: [<ffffffff810464b4>] ? default_wake_function+0x0/0x14
Jan 17 15:37:37 localhost kernel: [<ffffffff81286969>] tty_write+0x19d/0x245
Jan 17 15:37:37 localhost kernel: [<ffffffff81289592>] ? n_tty_write+0x0/0x351
Jan 17 15:37:37 localhost kernel: [<ffffffff81103e44>] vfs_write+0xae/0x10b
Jan 17 15:37:37 localhost kernel: [<ffffffff81103f61>] sys_write+0x4a/0x6e
Jan 17 15:37:37 localhost kernel: [<ffffffff81009e45>] tracesys+0xd9/0xde

The commit before this works fine.
-- 
Matthew Garrett | mjg59@srcf.ucam.org

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Marcel Holtmann]

Hi Matthew,

> gobi_loader writes firmware to gobi USB devices (qcserial) via the USB 
> serial layer by writing it a megabyte at a time (matching the Windows 
> driver behaviour). Commit 8e8dce065088833fc418bfa5fbf035cb0726c04c 
> breaks it - strace shows the write simply hanging. ssyrq-t says the 
> backtrace is:
> 
> Jan 17 15:37:37 localhost kernel: Call Trace:
> Jan 17 15:37:37 localhost kernel: [<ffffffff8128986c>] n_tty_write+0x2da/0x351
> Jan 17 15:37:37 localhost kernel: [<ffffffff810464b4>] ? default_wake_function+0x0/0x14
> Jan 17 15:37:37 localhost kernel: [<ffffffff81286969>] tty_write+0x19d/0x245
> Jan 17 15:37:37 localhost kernel: [<ffffffff81289592>] ? n_tty_write+0x0/0x351
> Jan 17 15:37:37 localhost kernel: [<ffffffff81103e44>] vfs_write+0xae/0x10b
> Jan 17 15:37:37 localhost kernel: [<ffffffff81103f61>] sys_write+0x4a/0x6e
> Jan 17 15:37:37 localhost kernel: [<ffffffff81009e45>] tracesys+0xd9/0xde
> 
> The commit before this works fine.

maybe I should have finished my libusb version of the gobi_loader ;)

Regards

Marcel

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Oliver Neukum]

Am Sonntag, 17. Januar 2010 03:55:35 schrieb Matthew Garrett:
> gobi_loader writes firmware to gobi USB devices (qcserial) via the USB 
> serial layer by writing it a megabyte at a time (matching the Windows 
> driver behaviour). Commit 8e8dce065088833fc418bfa5fbf035cb0726c04c 
> breaks it - strace shows the write simply hanging. ssyrq-t says the 
> backtrace is:
> 
> Jan 17 15:37:37 localhost kernel: Call Trace:
> Jan 17 15:37:37 localhost kernel: [<ffffffff8128986c>] n_tty_write+0x2da/0x351
> Jan 17 15:37:37 localhost kernel: [<ffffffff810464b4>] ? default_wake_function+0x0/0x14
> Jan 17 15:37:37 localhost kernel: [<ffffffff81286969>] tty_write+0x19d/0x245
> Jan 17 15:37:37 localhost kernel: [<ffffffff81289592>] ? n_tty_write+0x0/0x351
> Jan 17 15:37:37 localhost kernel: [<ffffffff81103e44>] vfs_write+0xae/0x10b
> Jan 17 15:37:37 localhost kernel: [<ffffffff81103f61>] sys_write+0x4a/0x6e
> Jan 17 15:37:37 localhost kernel: [<ffffffff81009e45>] tracesys+0xd9/0xde

Hi,

please load usbserial with debug=1 and post the output of just before the hang.

	Regards
		Oliver

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Matthew Garrett]

On Sun, Jan 17, 2010 at 10:14:44AM +0100, Oliver Neukum wrote:

> please load usbserial with debug=1 and post the output of just before the hang.

drivers/usb/serial/generic.c: usb_serial_generic_write_bulk_callback - 
port 0
qcserial ttyUSB0: usb_serial_generic_write_start - length = 512, data = 
01 00 a0 e1 60 07 00 ea 00 00 9f e5 37 07 00 ea 54 60 01 b0 04 e0 2d e5 
20 30 9f e5 04 d0 4d e2 00 10 a0 e1 0d 20 a0 e1 00 00 93 e5 01 1b 00 eb 
00 00 50 e3 00 00 e0 13 04 d0 8d e2 00 80 bd e8 3c 70 01 b0 01 00 12 e3 
70 40 2d e9 02 40 a0 e1 00 50 a0 e1 01 60 a0 e1 25 00 00 0a 20 40 85 e5 
fc 00 9f e5 06 10 a0 e1 1b f7 ff eb 01 00 70 e3 08 00 85 e5 70 80 bd 08 
06 30 80 e0 01 20 43 e2 10 40 14 e2 0c 20 85 e5 13 00 00 1a 00 10 a0 e1 
d0 00 9f e5 7a f7 ff eb 00 00 50 e3 2a 00 00 0a ff 34 a0 e3 f0 2f 93 e5 
05 10 a0 e1 00 00 92 e5 07 20 a0 e3 81 fe ff eb 00 00 50 e3 1c 00 00 1a 
0c 30 85 e2 0c 00 13 e8 02 20 43 e0 04 10 a0 e1 01 20 82 e2 08 00 95 e5 
78 12 00 eb 05 00 a0 e1 cb ff ff eb 00 40 50 e2 07 00 00 1a 04 00 a0 e1 
70 80 bd e8 70 00 9f e5 70 10 9f e5 70 20 9f e5 9d 30 a0 e3 da 11 00 eb 
d3 ff ff ea 08 10 85 e2 06 00 91 e8 48 00 9f e5 53 f6 ff eb 0c 20 95 e5 
40 00 9f e5 08 10 95 e5 31 f7 ff eb 04 00 a0 e1 70 80 bd e8 3c 00 9f e5 
30 10 9f e5 30 20 9f e5 af 30 a0 e3 ca 11 00 eb dc ff ff ea 10 00 9f e5 
08 10 85 e2 06 00 91 e8 43 f6 ff eb 00 00 e0 e3 70 80 bd e8 00 b0 01 b0 
00 80 01 b0 10 ca 00 b0 24 ca 00 b0 94 c9 00 b0 54 c6 00 b0 02 00 13 e3 
f0 41 2d e9 03 70 a0 e1 00 60 a0 e1 01 40 a0 e1 02 50 a0 e1 15 00 00 0a 
04 30 85 e0 01 40 43 e2 20 70 86 e5 08 50 86 e5 0c 40 86 e5 06 00 a0 e1 
97 ff ff eb 00 80 50 e2 08 00 a0 11 f0 81 bd 18 04 20 a0 e1 c4 00 9f e5 
05 10 a0 e1 54 f7 ff eb 04 20 a0 e1 05 10 a0 e1 b4 00 9f e5 50 f7 ff eb 
10 40 17 e2 07 00 00 0a 08 00 a0 e1 f0 81 bd e8 a0 00 9f e5 a0 10 9f e5 
a0 20 9f e5 c3 30 a0 e3 
drivers/usb/serial/generic.c: usb_serial_generic_write - port 0
drivers/usb/serial/usb-serial.c: serial_write - port 0, 1536 byte(s)
drivers/usb/serial/generic.c: usb_serial_generic_write - port 0
drivers/usb/serial/usb-serial.c: usb_serial_port_work - port 0
drivers/usb/serial/usb-serial.c: serial_write - port 0, 1536 byte(s)
drivers/usb/serial/generic.c: usb_serial_generic_write - port 0

-- 
Matthew Garrett | mjg59@srcf.ucam.org

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Oliver Neukum]

[-- Attachment #1: Type: Text/Plain, Size: 561 bytes --]

Am Montag, 18. Januar 2010 02:58:44 schrieb Matthew Garrett:
> drivers/usb/serial/generic.c: usb_serial_generic_write - port 0
> drivers/usb/serial/usb-serial.c: serial_write - port 0, 1536 byte(s)
> drivers/usb/serial/generic.c: usb_serial_generic_write - port 0
> drivers/usb/serial/usb-serial.c: usb_serial_port_work - port 0
> drivers/usb/serial/usb-serial.c: serial_write - port 0, 1536 byte(s)
> drivers/usb/serial/generic.c: usb_serial_generic_write - port 0

Hi,

it is not conclusive. Can you apply the attached patch and try again?

	Regards
		Oliver

[-- Attachment #2: 0001-additional-debugging.patch --]
[-- Type: text/x-patch, Size: 1420 bytes --]

From 27e54a5d36aba23276d30bd61b962916dca7a946 Mon Sep 17 00:00:00 2001
From: Oliver Neukum <oliver@neukum.org>
Date: Mon, 18 Jan 2010 18:23:09 +0100
Subject: [PATCH] additional debugging

---
 drivers/usb/serial/generic.c |    5 ++++-
 1 files changed, 4 insertions(+), 1 deletions(-)

diff --git a/drivers/usb/serial/generic.c b/drivers/usb/serial/generic.c
index f1ea3a3..76e5514 100644
--- a/drivers/usb/serial/generic.c
+++ b/drivers/usb/serial/generic.c
@@ -283,6 +283,8 @@ static int usb_serial_generic_write_start(struct usb_serial_port *port)
 
 	if (!start_io)
 		return 0;
+	
+	dbg("%s - starting IO", __func__);
 
 	data = port->write_urb->transfer_buffer;
 	count = kfifo_out_locked(&port->write_fifo, data, port->bulk_out_size, &port->lock);
@@ -330,7 +332,7 @@ int usb_serial_generic_write(struct tty_struct *tty,
 	struct usb_serial *serial = port->serial;
 	int result;
 
-	dbg("%s - port %d", __func__, port->number);
+	dbg("%s - port %d, %d bytes", __func__, port->number, count);
 
 	if (count == 0) {
 		dbg("%s - write request of 0 bytes", __func__);
@@ -346,6 +348,7 @@ int usb_serial_generic_write(struct tty_struct *tty,
 						  buf, count);
 
 	count = kfifo_in_locked(&port->write_fifo, buf, count, &port->lock);
+	dbg("%s - put %d bytes into fifo", __func__, count);
 	result = usb_serial_generic_write_start(port);
 
 	if (result >= 0)
-- 
1.6.4.2

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Matthew Garrett]

On Mon, Jan 18, 2010 at 06:25:39PM +0100, Oliver Neukum wrote:

> it is not conclusive. Can you apply the attached patch and try again?

qcserial ttyUSB0: usb_serial_generic_write_start - length = 512, data = 
drivers/usb/serial/generic.c: usb_serial_generic_write - put 1024 bytes 
into fifo
drivers/usb/serial/usb-serial.c: serial_write - port 0, 29 byte(s)
drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 29 
bytes
drivers/usb/serial/generic.c: usb_serial_generic_write - put 0 bytes 
into fifo
e1 0e 20 83 e0 40 10 92 e5 01 00 80 e2 0c 30 83 e0 02 00 50 e3 e8 10 83 
e5 f7 ff ff da 0c 30 9e e5 f4 30 8c e5 24 10 9c e5 1c
 20 9e e5 20 00 9c e5 00 30 a0 e3 14 30 8c e5 f8 20 8c e5 08 11 8c e5 0c 
01 8c e5 04 f0 9d e4 04 d0 4d e2 01 60 a0 e1 02 70 a
0 e1 03 40 a0 e1 00 50 a0 e1 04 80 9d e5 e1 ff ff eb 78 31 9f e5 0c 20 
95 e5 00 10 93 e5 01 00 52 e1 40 00 00 0a 00 00 54 e3 
1f 30 e0 13 1b 30 e0 03 01 00 54 e3 00 20 a0 13 01 20 a0 03 82 30 83 e1 
03 00 54 e3 03 20 a0 11 01 20 83 03 02 00 54 e3 06 20
 82 03 02 30 a0 e3 00 30 8d e5 b2 20 cd e1 00 30 9d e5 08 c0 95 e5 03 39 
83 e3 00 30 8d e5 40 30 8c e5 44 60 8c e5 48 70 8c e5 1c 00 95 e5 a0 32 
a0 e1 7f 3f c3 e3 ff 33 c3 e3 0f 35 c3 e3 0e e2 83 e2 08 10 9e e5 00 00 
51 e3 14 00 00 0a 0a 30 d1 e5 60 31 8e e5 0b 20 d1 e5 64 21 8e e5 0a 30 
dc e5 0a 30 c1 e5 08 20 95 e5 0b 30 d2 e5 0b 30 c1 e5 7c 30 95 e5 38 20 
8e e2 80 00 13 e3 44 30 92 15 80 30 83 13 44 30 82 15 7c 30 95 15 40 00 
13 e3 44 30 92 15 40 30 83 13 44 30 82 15 1c 00 95 e5 0f 22 a0 e3 04 10 
92 e5 2c 30 91 e5 8c 20 9f e5 01 30 83 e3 2c 30 81 e5 80 20 85 e5 50 81 
85 e5 7c 30 9f e5 00 10 a0 e1 78 e0 9f e5 03 f0 a0 e1 fe ff ff ea 1c 30 
95 e5 00 00 53 e3 bb ff ff 1a 01 00 54 e3 60 10 9f 05 0a 00 00 0a 00 00 
54 e3 58 10 9f 05 07 00 00 0a 03 00 54 e3 50 10 9f 05 04 00 00 0a 4c 20 
9f e5 4c 30 9f e5 02 00 54 e3 02 10 a0 11 03 10 a0 01 06 20 a0 e1 07 30 
a0 e1 38 00 9f e5 b4 3e 00 eb 34 00 9f e5 dd 05 00 eb fe df 8d e3 08 f0 
a0 e1 fe ff ff ea f0 c1 01 f0 f4 7f 00 f0 8c 89 00 f0 10 b6 00 f0 e0 0a 
01 f0 e8 0a 01 f0 f0 0a 01 
drivers/usb/serial/usb-serial.c: usb_serial_port_work - port 0
drivers/usb/serial/usb-serial.c: serial_write - port 0, 29 byte(s)
drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 29 
bytes
drivers/usb/serial/generic.c: usb_serial_generic_write - put 0 bytes 
into fifo
drivers/usb/serial/generic.c: usb_serial_generic_write_bulk_callback - 
port 0
drivers/usb/serial/generic.c: usb_serial_generic_write_start - starting 
IO
qcserial ttyUSB0: usb_serial_generic_write_start - length = 512, data = 
f0 f8 0a 01 f0 00 0b 01 f0 0c 10 01 f0 38 10 01 f0 0f 22 a0 e3 04 40 92 
e5 1c 30 94 e5 a3 32 a0 e1 7f 3f c3 e3 ff 33 c3 e3 0f 35 c3 e3 0e 12 83 
e2 08 00 91 e5 00 00 50 e3 0a 00 00 0a 0a 20 d0 e5 02 00 52 e3 0d 00 00 
0a 60 31 91 e5 0a 30 c0 e5 64 21 91 e5 0b 20 c0 e5 38 10 81 e2 44 30 91 
e5 c0 30 c3 e3 44 30 81 e5 04 00 a0 e1 96 fc ff eb 50 31 94 e5 fe df 8d 
e3 03 f0 a0 e1 fe ff ff ea 08 30 94 e5 0a 20 c3 e5 38 20 84 e2 44 30 92 
e5 80 30 83 e3 44 30 82 e5 ea ff ff ea 02 60 a0 e1 01 50 a0 e1 04 d0 4d 
e2 00 70 a0 e1 03 80 a0 e1 4d ff ff eb a5 2f a0 e1 86 30 82 e1 00 00 a0 
e3 2f 20 e0 e3 00 00 8d e5 b2 20 cd e1 00 10 9d e5 03 19 81 e3 00 10 8d 
e5 a6 4f a0 e1 a3 20 a0 e1 84 3f 82 e1 08 20 97 e5 48 30 82 e5 0f 32 a0 
e3 40 10 82 e5 0c 00 82 e5 44 50 82 e5 04 10 93 e5 2c 30 91 e5 e4 00 97 
e5 20 20 9f e5 01 30 83 e3 2c 30 81 e5 80 20 87 e5 50 81 87 e5 10 30 9f 
e5 00 10 a0 e1 0c e0 9f e5 03 f0 a0 e1 fe ff ff ea 20 81 00 f0 8c 89 00 
f0 10 b6 00 f0 0f 32 a0 e3 04 40 93 e5 08 20 94 e5 40 30 92 e5 04 d0 4d 
e2 00 30 8d e5 04 00 a0 e1 5b fc ff eb d1 30 dd e1 00 00 53 e3 03 00 00 
ba 50 31 94 e5 fe df 8d e3 03 f0 a0 e1 fe ff ff ea 04 00 9f e5 73 05 00 
eb f8 ff ff ea 4c 10 01 f0 0f c2 a0 e3 18 40 dc e5 18 d0 4d e2 00 00 54 
e3 0e 60 a0 e1 14 00 8d e5 01 a0 a0 e1 10 20 8d e5 03 90 a0 e1 20 b0 9d 
e5 51 01 00 1a 0f 32 a0 e3 04 80 93 e5 50 26 9f e5 0c 30 98 e5 00 10 92 
e5 01 00 53 e1 00 00 a0 13 01 00 a0 03 00 00 50 e3 41 01 00 0a 14 50 9d 
e5 01 20 75 e2 00 20 a0 33 00 00 52 e3 0d 00 00 1a b4 31 dd e1 3f 00 13 
e3 02 30 a0 e1 03 00 00 
drivers/usb/serial/usb-serial.c: usb_serial_port_work - port 0
drivers/usb/serial/usb-serial.c: serial_write - port 0, 29 byte(s)
drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 29 
bytes
drivers/usb/serial/generic.c: usb_serial_generic_write - put 29 bytes 
into fifo
drivers/usb/serial/usb-serial.c: serial_write - port 0, 2048 byte(s)
drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 2048 
bytes
drivers/usb/serial/generic.c: usb_serial_generic_write - put 483 bytes 
into fifo
drivers/usb/serial/usb-serial.c: serial_write - port 0, 1565 byte(s)
drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 1565 
bytes
drivers/usb/serial/generic.c: usb_serial_generic_write - put 0 bytes 
into fifo
drivers/usb/serial/generic.c: usb_serial_generic_read_bulk_callback - 
port 0

-- 
Matthew Garrett | mjg59@srcf.ucam.org

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Oliver Neukum]

[-- Attachment #1: Type: Text/Plain, Size: 399 bytes --]

Am Montag, 18. Januar 2010 21:14:16 schrieb Matthew Garrett:

> drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 1565 
> bytes
> drivers/usb/serial/generic.c: usb_serial_generic_write - put 0 bytes 
> into fifo
> drivers/usb/serial/generic.c: usb_serial_generic_read_bulk_callback - 
> port 0

If the FIFO is full we can do nothing. Please try the attached patch.

	Regards
		Oliver

[-- Attachment #2: 0001-usb-serial-Deal-with-filled-FIFO.patch --]
[-- Type: text/x-patch, Size: 938 bytes --]

From d7317bae0772b794a1cc9b832bc3d3e1b3642a13 Mon Sep 17 00:00:00 2001
From: Oliver Neukum <oliver@neukum.org>
Date: Tue, 19 Jan 2010 14:16:41 +0100
Subject: [PATCH] usb:serial:Deal with filled FIFO

Bail out if the FIFO is filled

Signed-off-by: Oliver Neukum <oliver@neukum.org>
---
 drivers/usb/serial/generic.c |    4 ++++
 1 files changed, 4 insertions(+), 0 deletions(-)

diff --git a/drivers/usb/serial/generic.c b/drivers/usb/serial/generic.c
index 76e5514..053f7f1 100644
--- a/drivers/usb/serial/generic.c
+++ b/drivers/usb/serial/generic.c
@@ -349,6 +349,10 @@ int usb_serial_generic_write(struct tty_struct *tty,
 
 	count = kfifo_in_locked(&port->write_fifo, buf, count, &port->lock);
 	dbg("%s - put %d bytes into fifo", __func__, count);
+	if (!count) {
+		dbg("%s - FIFO is full", __func__);
+		return 0;
+	}
 	result = usb_serial_generic_write_start(port);
 
 	if (result >= 0)
-- 
1.6.4.2

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Alan Cox]

On Tue, 19 Jan 2010 14:20:29 +0100
Oliver Neukum <oliver@neukum.org> wrote:

> Am Montag, 18. Januar 2010 21:14:16 schrieb Matthew Garrett:
> 
> > drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 1565 
> > bytes
> > drivers/usb/serial/generic.c: usb_serial_generic_write - put 0 bytes 
> > into fifo
> > drivers/usb/serial/generic.c: usb_serial_generic_read_bulk_callback - 
> > port 0
> 
> If the FIFO is full we can do nothing. Please try the attached patch.

If the FIFO is full how are we getting called - we should have throttled
earlier if there is any flow control (including 'look no URBs' cases) ?

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Oliver Neukum]

Am Dienstag, 19. Januar 2010 14:29:34 schrieb Alan Cox:
> On Tue, 19 Jan 2010 14:20:29 +0100
> Oliver Neukum <oliver@neukum.org> wrote:
> 
> > Am Montag, 18. Januar 2010 21:14:16 schrieb Matthew Garrett:
> > 
> > > drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 1565 
> > > bytes
> > > drivers/usb/serial/generic.c: usb_serial_generic_write - put 0 bytes 
> > > into fifo
> > > drivers/usb/serial/generic.c: usb_serial_generic_read_bulk_callback - 
> > > port 0
> > 
> > If the FIFO is full we can do nothing. Please try the attached patch.
> 
> If the FIFO is full how are we getting called - we should have throttled
> earlier if there is any flow control (including 'look no URBs' cases) ?

The log shows no call to usb_serial_generic_write_room()
Do you consider this a bug in the tty layer?

	Regards
		Oliver

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Alan Cox]

On Tue, 19 Jan 2010 14:57:00 +0100
Oliver Neukum <oliver@neukum.org> wrote:

> Am Dienstag, 19. Januar 2010 14:29:34 schrieb Alan Cox:
> > On Tue, 19 Jan 2010 14:20:29 +0100
> > Oliver Neukum <oliver@neukum.org> wrote:
> > 
> > > Am Montag, 18. Januar 2010 21:14:16 schrieb Matthew Garrett:
> > > 
> > > > drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 1565 
> > > > bytes
> > > > drivers/usb/serial/generic.c: usb_serial_generic_write - put 0 bytes 
> > > > into fifo
> > > > drivers/usb/serial/generic.c: usb_serial_generic_read_bulk_callback - 
> > > > port 0
> > > 
> > > If the FIFO is full we can do nothing. Please try the attached patch.
> > 
> > If the FIFO is full how are we getting called - we should have throttled
> > earlier if there is any flow control (including 'look no URBs' cases) ?
> 
> The log shows no call to usb_serial_generic_write_room()
> Do you consider this a bug in the tty layer?

Some of the line disciplines just throw data at the board but not n_tty
(the normal one) - so for PPP you wouldn't see checks on room but the
loader I assume is using the normal tty layer - if so something is up
because the ldisc shouldn't have written more than there is room for.

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Alan Cox]

> The log shows no call to usb_serial_generic_write_room()
> Do you consider this a bug in the tty layer?

Actually this all makes sense because of where it was hanging. A reply of
0 to the tty->ops->write will cause it to either return (O_NONBLOCK) or
sleep in the n_tty write code waiting for a write_wait wakeup
(tty_wakeup(tty))

So the fix does indeed look correct.

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Oliver Neukum]

Am Dienstag, 19. Januar 2010 15:21:24 schrieb Alan Cox:
> > > > If the FIFO is full we can do nothing. Please try the attached patch.
> > > 
> > > If the FIFO is full how are we getting called - we should have throttled
> > > earlier if there is any flow control (including 'look no URBs' cases) ?
> > 
> > The log shows no call to usb_serial_generic_write_room()
> > Do you consider this a bug in the tty layer?
> 
> Some of the line disciplines just throw data at the board but not n_tty
> (the normal one) - so for PPP you wouldn't see checks on room but the
> loader I assume is using the normal tty layer - if so something is up
> because the ldisc shouldn't have written more than there is room for.

I don't know which line discipline is used. Matthew?

But anyway, if this can happen buglessly, the generic function
must handle it.

	Regards
		Oliver

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Johan Hovold]

> > The log shows no call to usb_serial_generic_write_room()
> > Do you consider this a bug in the tty layer?
> 
> Actually this all makes sense because of where it was hanging. A reply of
> 0 to the tty->ops->write will cause it to either return (O_NONBLOCK) or
> sleep in the n_tty write code waiting for a write_wait wakeup
> (tty_wakeup(tty))
> 
> So the fix does indeed look correct.

Is it really a fix? If the fifo is already full the write urb should be
in use and Oliver's patch would amount to only a minor optimisation as
usb_serial_generic_write_start would return 0 anyway.

/Johan

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Johan Hovold]

> > > The log shows no call to usb_serial_generic_write_room()
> > > Do you consider this a bug in the tty layer?
> > 
> > Actually this all makes sense because of where it was hanging. A reply of
> > 0 to the tty->ops->write will cause it to either return (O_NONBLOCK) or
> > sleep in the n_tty write code waiting for a write_wait wakeup
> > (tty_wakeup(tty))
> > 
> > So the fix does indeed look correct.
> 
> Is it really a fix? If the fifo is already full the write urb should be
> in use and Oliver's patch would amount to only a minor optimisation as
> usb_serial_generic_write_start would return 0 anyway.

So the question seems to be: why doesn't the on-going transfer finish (so
that tty_wakeup is called)?


> drivers/usb/serial/usb-serial.c: usb_serial_port_work - port 0
> drivers/usb/serial/usb-serial.c: serial_write - port 0, 29 byte(s)
> drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 29
> bytes
> drivers/usb/serial/generic.c: usb_serial_generic_write - put 0 bytes
> into fifo

Writer got woken but fifo is still full so write returns 0 and writer goes
back to sleep.

> drivers/usb/serial/generic.c: usb_serial_generic_write_bulk_callback -
> port 0
> drivers/usb/serial/generic.c: usb_serial_generic_write_start - starting
> IO
> qcserial ttyUSB0: usb_serial_generic_write_start - length = 512, data =
> f0 f8 0a 01 f0 00 0b 01 f0 0c 10 01 f0 38 10 01 f0 0f 22 a0 e3 04 40 92
> e5 1c 30 94 e5 a3 32 a0 e1 7f 3f c3 e3 ff 33 c3 e3 0f 35 c3 e3 0e 12 83
> e2 08 00 91 e5 00 00 50 e3 0a 00 00 0a 0a 20 d0 e5 02 00 52 e3 0d 00 00
> 0a 60 31 91 e5 0a 30 c0 e5 64 21 91 e5 0b 20 c0 e5 38 10 81 e2 44 30 91
> e5 c0 30 c3 e3 44 30 81 e5 04 00 a0 e1 96 fc ff eb 50 31 94 e5 fe df 8d
> e3 03 f0 a0 e1 fe ff ff ea 08 30 94 e5 0a 20 c3 e5 38 20 84 e2 44 30 92
> e5 80 30 83 e3 44 30 82 e5 ea ff ff ea 02 60 a0 e1 01 50 a0 e1 04 d0 4d
> e2 00 70 a0 e1 03 80 a0 e1 4d ff ff eb a5 2f a0 e1 86 30 82 e1 00 00 a0
> e3 2f 20 e0 e3 00 00 8d e5 b2 20 cd e1 00 10 9d e5 03 19 81 e3 00 10 8d
> e5 a6 4f a0 e1 a3 20 a0 e1 84 3f 82 e1 08 20 97 e5 48 30 82 e5 0f 32 a0
> e3 40 10 82 e5 0c 00 82 e5 44 50 82 e5 04 10 93 e5 2c 30 91 e5 e4 00 97
> e5 20 20 9f e5 01 30 83 e3 2c 30 81 e5 80 20 87 e5 50 81 87 e5 10 30 9f
> e5 00 10 a0 e1 0c e0 9f e5 03 f0 a0 e1 fe ff ff ea 20 81 00 f0 8c 89 00
> f0 10 b6 00 f0 0f 32 a0 e3 04 40 93 e5 08 20 94 e5 40 30 92 e5 04 d0 4d
> e2 00 30 8d e5 04 00 a0 e1 5b fc ff eb d1 30 dd e1 00 00 53 e3 03 00 00
> ba 50 31 94 e5 fe df 8d e3 03 f0 a0 e1 fe ff ff ea 04 00 9f e5 73 05 00
> eb f8 ff ff ea 4c 10 01 f0 0f c2 a0 e3 18 40 dc e5 18 d0 4d e2 00 00 54
> e3 0e 60 a0 e1 14 00 8d e5 01 a0 a0 e1 10 20 8d e5 03 90 a0 e1 20 b0 9d
> e5 51 01 00 1a 0f 32 a0 e3 04 80 93 e5 50 26 9f e5 0c 30 98 e5 00 10 92
> e5 01 00 53 e1 00 00 a0 13 01 00 a0 03 00 00 50 e3 41 01 00 0a 14 50 9d
> e5 01 20 75 e2 00 20 a0 33 00 00 52 e3 0d 00 00 1a b4 31 dd e1 3f 00 13
> e3 02 30 a0 e1 03 00 00

New transfer started from completion handler.

> drivers/usb/serial/usb-serial.c: usb_serial_port_work - port 0

Writer woken up from completion handler after having started the
next transfer.

> drivers/usb/serial/usb-serial.c: serial_write - port 0, 29 byte(s)
> drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 29
> bytes
> drivers/usb/serial/generic.c: usb_serial_generic_write - put 29 bytes
> into fifo
> drivers/usb/serial/usb-serial.c: serial_write - port 0, 2048 byte(s)
> drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 2048
> bytes
> drivers/usb/serial/generic.c: usb_serial_generic_write - put 483 bytes
> into fifo
> drivers/usb/serial/usb-serial.c: serial_write - port 0, 1565 byte(s)
> drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 1565
> bytes
> drivers/usb/serial/generic.c: usb_serial_generic_write - put 0 bytes
> into fifo

Now there was some room (29 + 483 = 512 bytes bytes just transfered).

> drivers/usb/serial/generic.c: usb_serial_generic_read_bulk_callback -
> port 0

Waiting forever for on-going transfer to finish...

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Alan Cox]

On Tue, 19 Jan 2010 16:25:36 +0100
Johan Hovold <jhovold@gmail.com> wrote:

> > > The log shows no call to usb_serial_generic_write_room()
> > > Do you consider this a bug in the tty layer?
> > 
> > Actually this all makes sense because of where it was hanging. A reply of
> > 0 to the tty->ops->write will cause it to either return (O_NONBLOCK) or
> > sleep in the n_tty write code waiting for a write_wait wakeup
> > (tty_wakeup(tty))
> > 
> > So the fix does indeed look correct.
> 
> Is it really a fix? If the fifo is already full the write urb should be
> in use and Oliver's patch would amount to only a minor optimisation as
> usb_serial_generic_write_start would return 0 anyway.

IF the write returns a zero then it will sleep in n_tty waiting for a
wakeup when the FIFO level drops sufficiently. If that isn't working
check that all cases where data is cleared from the FIFO called
tty_wakeup and do so *after* the FIFO has been partly emptied and the
locking has ensured the space is visible to the write side.

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Oliver Neukum]

Am Dienstag, 19. Januar 2010 17:27:46 schrieb Alan Cox:
> On Tue, 19 Jan 2010 16:25:36 +0100
> Johan Hovold <jhovold@gmail.com> wrote:

> > Is it really a fix? If the fifo is already full the write urb should be
> > in use and Oliver's patch would amount to only a minor optimisation as
> > usb_serial_generic_write_start would return 0 anyway.
> 
> IF the write returns a zero then it will sleep in n_tty waiting for a
> wakeup when the FIFO level drops sufficiently. If that isn't working
> check that all cases where data is cleared from the FIFO called
> tty_wakeup and do so *after* the FIFO has been partly emptied and the
> locking has ensured the space is visible to the write side.
> 
usb_serial_generic_write_bulk_callback() always calls the softint
in the single URB case. Therefore the test with the patch I sent.
It is unlikely to be chance that the hang happens just as the FIFO
is full.

	Regards
		Oliver

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Johan Hovold]

On Tue, Jan 19, 2010 at 07:44:54PM +0100, Oliver Neukum wrote:
> Am Dienstag, 19. Januar 2010 17:27:46 schrieb Alan Cox:
> > On Tue, 19 Jan 2010 16:25:36 +0100
> > Johan Hovold <jhovold@gmail.com> wrote:
> 
> > > Is it really a fix? If the fifo is already full the write urb should be
> > > in use and Oliver's patch would amount to only a minor optimisation as
> > > usb_serial_generic_write_start would return 0 anyway.
> > 
> > IF the write returns a zero then it will sleep in n_tty waiting for a
> > wakeup when the FIFO level drops sufficiently. If that isn't working
> > check that all cases where data is cleared from the FIFO called
> > tty_wakeup and do so *after* the FIFO has been partly emptied and the
> > locking has ensured the space is visible to the write side.
> > 
> usb_serial_generic_write_bulk_callback() always calls the softint
> in the single URB case. Therefore the test with the patch I sent.
> It is unlikely to be chance that the hang happens just as the FIFO
> is full.

But that is the correct behaviour: for every kfifo_get, exactly one urb
is submitted and on completion softint (tty_wake) is called. I guess we
could call softint from usb_serial_generic_write_start (after the
kfifo_get is made) but we would still have a 1-1 mapping.

In the log posted earlier everything looks fine with respect to fifo
put/get. What is apparent though is that the last write urb submitted
never completes (and consequently, the writing process is never woken).

And by the way, as the application in question is doing megabyte writes
at a time, isn't the fifo quite likely to be full most of the time?

/Johan

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Greg KH]

On Tue, Jan 19, 2010 at 02:20:29PM +0100, Oliver Neukum wrote:
> Am Montag, 18. Januar 2010 21:14:16 schrieb Matthew Garrett:
> 
> > drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 1565 
> > bytes
> > drivers/usb/serial/generic.c: usb_serial_generic_write - put 0 bytes 
> > into fifo
> > drivers/usb/serial/generic.c: usb_serial_generic_read_bulk_callback - 
> > port 0
> 
> If the FIFO is full we can do nothing. Please try the attached patch.

Did we ever determine if the patch below is needed or not?

thanks,

greg k-h

> From d7317bae0772b794a1cc9b832bc3d3e1b3642a13 Mon Sep 17 00:00:00 2001
> From: Oliver Neukum <oliver@neukum.org>
> Date: Tue, 19 Jan 2010 14:16:41 +0100
> Subject: [PATCH] usb:serial:Deal with filled FIFO
> 
> Bail out if the FIFO is filled
> 
> Signed-off-by: Oliver Neukum <oliver@neukum.org>
> ---
>  drivers/usb/serial/generic.c |    4 ++++
>  1 files changed, 4 insertions(+), 0 deletions(-)
> 
> diff --git a/drivers/usb/serial/generic.c b/drivers/usb/serial/generic.c
> index 76e5514..053f7f1 100644
> --- a/drivers/usb/serial/generic.c
> +++ b/drivers/usb/serial/generic.c
> @@ -349,6 +349,10 @@ int usb_serial_generic_write(struct tty_struct *tty,
>  
>  	count = kfifo_in_locked(&port->write_fifo, buf, count, &port->lock);
>  	dbg("%s - put %d bytes into fifo", __func__, count);
> +	if (!count) {
> +		dbg("%s - FIFO is full", __func__);
> +		return 0;
> +	}
>  	result = usb_serial_generic_write_start(port);
>  
>  	if (result >= 0)
> -- 
> 1.6.4.2
> 

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Oliver Neukum]

Am Donnerstag, 28. Januar 2010 18:45:46 schrieb Greg KH:
> On Tue, Jan 19, 2010 at 02:20:29PM +0100, Oliver Neukum wrote:
> > Am Montag, 18. Januar 2010 21:14:16 schrieb Matthew Garrett:
> > 
> > > drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 1565 
> > > bytes
> > > drivers/usb/serial/generic.c: usb_serial_generic_write - put 0 bytes 
> > > into fifo
> > > drivers/usb/serial/generic.c: usb_serial_generic_read_bulk_callback - 
> > > port 0
> > 
> > If the FIFO is full we can do nothing. Please try the attached patch.
> 
> Did we ever determine if the patch below is needed or not?

No. Further discussion cast serious doubt on it, but we have no
experimental evidence I am aware of.

	Regards
		Oliver

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Greg KH]

On Thu, Jan 28, 2010 at 07:40:12PM +0100, Oliver Neukum wrote:
> Am Donnerstag, 28. Januar 2010 18:45:46 schrieb Greg KH:
> > On Tue, Jan 19, 2010 at 02:20:29PM +0100, Oliver Neukum wrote:
> > > Am Montag, 18. Januar 2010 21:14:16 schrieb Matthew Garrett:
> > > 
> > > > drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 1565 
> > > > bytes
> > > > drivers/usb/serial/generic.c: usb_serial_generic_write - put 0 bytes 
> > > > into fifo
> > > > drivers/usb/serial/generic.c: usb_serial_generic_read_bulk_callback - 
> > > > port 0
> > > 
> > > If the FIFO is full we can do nothing. Please try the attached patch.
> > 
> > Did we ever determine if the patch below is needed or not?
> 
> No. Further discussion cast serious doubt on it, but we have no
> experimental evidence I am aware of.

Ok, thanks for letting me know.

greg k-h

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Matthew Garrett]

On Tue, Jan 19, 2010 at 02:20:29PM +0100, Oliver Neukum wrote:
> Am Montag, 18. Januar 2010 21:14:16 schrieb Matthew Garrett:
> 
> > drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 1565 
> > bytes
> > drivers/usb/serial/generic.c: usb_serial_generic_write - put 0 bytes 
> > into fifo
> > drivers/usb/serial/generic.c: usb_serial_generic_read_bulk_callback - 
> > port 0
> 
> If the FIFO is full we can do nothing. Please try the attached patch.

Doesn't help, I'm afraid. Does anyone have any idea why the change to 
use kfifo would cause this?

-- 
Matthew Garrett | mjg59@srcf.ucam.org

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Oliver Neukum]

Am Mittwoch, 3. Februar 2010 17:46:59 schrieb Matthew Garrett:
> > If the FIFO is full we can do nothing. Please try the attached patch.
> 
> Doesn't help, I'm afraid. Does anyone have any idea why the change to 
> use kfifo would cause this?

The logic seems sound. That is unless the kfifo code is acting up.
Could you printk the value kfifo_len returns in usb_serial_generic_write_start()?

	Regards
		Oliver

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Matthew Garrett]

On Wed, Feb 03, 2010 at 06:21:39PM +0100, Oliver Neukum wrote:
> Am Mittwoch, 3. Februar 2010 17:46:59 schrieb Matthew Garrett:
> > > If the FIFO is full we can do nothing. Please try the attached patch.
> > 
> > Doesn't help, I'm afraid. Does anyone have any idea why the change to 
> > use kfifo would cause this?
> 
> The logic seems sound. That is unless the kfifo code is acting up.
> Could you printk the value kfifo_len returns in usb_serial_generic_write_start()?

kfifo_len is 4096 when it gets into the fifo_full situation.

-- 
Matthew Garrett | mjg59@srcf.ucam.org

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Oliver Neukum]

Am Mittwoch, 3. Februar 2010 23:37:37 schrieb Matthew Garrett:
> On Wed, Feb 03, 2010 at 06:21:39PM +0100, Oliver Neukum wrote:
> > Am Mittwoch, 3. Februar 2010 17:46:59 schrieb Matthew Garrett:
> > > > If the FIFO is full we can do nothing. Please try the attached patch.
> > > 
> > > Doesn't help, I'm afraid. Does anyone have any idea why the change to 
> > > use kfifo would cause this?
> > 
> > The logic seems sound. That is unless the kfifo code is acting up.
> > Could you printk the value kfifo_len returns in usb_serial_generic_write_start()?
> 
> kfifo_len is 4096 when it gets into the fifo_full situation.

Then this won't explain it either. Do you get to the line:
	dbg("%s - starting IO", __func__);
before it hangs?

	Regards
		Oliver

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Matthew Garrett]

This is what I get immediately before the hang.

drivers/usb/serial/usb-serial.c: usb_serial_port_work - port 0
drivers/usb/serial/usb-serial.c: serial_write - port 0, 1024 byte(s)
drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 1024 bytes
drivers/usb/serial/generic.c: usb_serial_generic_write - put 512 bytes into fifo
drivers/usb/serial/usb-serial.c: serial_write - port 0, 512 byte(s)
drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 512 bytes
drivers/usb/serial/generic.c: usb_serial_generic_write - put 0 bytes into fifo
drivers/usb/serial/generic.c: usb_serial_generic_write - FIFO is full
drivers/usb/serial/generic.c: usb_serial_generic_write_bulk_callback - port 0
drivers/usb/serial/generic.c: usb_serial_generic_write_start - starting IO
qcserial ttyUSB0: usb_serial_generic_write_start - length = 512, data = 28 10 94
 e5 0c 30 84 e2 0c 00 13 e8 02 20 43 e0 40 01 9f e5 02 20 81 e0 13 f7 ff eb 04 0
0 a0 e1 e6 01 00 eb 00 00 50 e3 3c 00 00 1a 00 30 96 e5 04 20 96 e5 04 20 83 e5 
04 10 96 e5 06 00 a0 e1 00 30 81 e5 d0 07 00 eb 08 d0 8d e2 f0 85 bd e8 04 00 a0
 e1 1b fe ff eb f8 00 9f e5 08 10 84 e2 06 00 91 e8 e2 f7 ff eb ec 00 9f e5 08 1
0 84 e2 06 00 91 e8 e7 ff ff ea 47 3f a0 e3 02 30 83 e2 d8 00 9f e5 d8 10 9f e5 
d8 20 9f e5 78 12 00 eb 20 30 94 e5 18 00 13 e3 d4 ff ff 0a 04 00 a0 e1 08 fe ff
 eb b0 00 9f e5 08 10 84 e2 06 00 91 e8 ed f6 ff eb 20 30 94 e5 10 00 13 e3 d6 f
f ff 0a 08 50 84 e2 a0 00 95 e8 07 00 55 e1 d2 ff ff 2a 04 a0 8d e2 0d 80 a0 e1 
03 00 00 ea 01 30 a0 e3 13 52 85 e0 07 00 55 e1 cb ff ff 2a 08 20 a0 e1 05 00 a0
 e1 0a 10 a0 e1 45 05 00 eb 0c 20 a0 e3 00 00 50 e3 04 20 8d 05 05 00 a0 e1 f2 f
f ff 0a 04 10 9d e5 e2 05 00 eb 04 20 9d e5 ee ff ff ea 4b 3f a0 e3 03 30 83 e2 
3c 00 9f e5 30 10 9f e5 30 20 9f e5 4e 12 00 eb bb ff ff ea 46 3f a0 e3 01 30 83
 e2 24 00 9f e5 14 10 9f e5 14 20 9f e5 47 12 00 eb 9f ff ff ea 00 80 01 b0 00 b
0 01 b0 64 c9 00 b0 f4 c7 00 b0 d8 c7 00 b0 54 c6 00 b0 8c c9 00 b0 00 00 90 e5 
45 11 a0 e3 7b 15 81 e2 71 1a 81 e2 00 20 a0 e1 08 30 92 e5 01 00 53 e1 05 00 00
 1a 00 20 92 e5 00 30 92 e5 00 00 53 e1 f8 ff ff 1a 01 00 a0 e3 1e ff 2f e1 00 00 a0 e3 1e ff 2f e1 30 40 2d e9 01 30 a0 e3 01 40 a0 e1 02 50 a0 e1 00 10 a0 e1 00 20 a0 e3 28 00 9f e5 70 02 00 eb 00 30 50 e2 30 80 bd 08 08 20 93 e5 00 20 84 e5 0c 20 83 e2 0c 00 12 e8 02 30 43 e0 01 30 83 e2 00 30 85 e5 30 80 bd e8 7c bc 01 b0 
drivers/usb/serial/usb-serial.c: usb_serial_port_work - port 0
drivers/usb/serial/usb-serial.c: serial_write - port 0, 512 byte(s)
drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 512 bytes
drivers/usb/serial/generic.c: usb_serial_generic_write - put 512 bytes into fifo
drivers/usb/serial/usb-serial.c: serial_write - port 0, 2048 byte(s)
drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 2048 bytes
drivers/usb/serial/generic.c: usb_serial_generic_write - put 0 bytes into fifo
drivers/usb/serial/generic.c: usb_serial_generic_write - FIFO is full
drivers/usb/serial/generic.c: usb_serial_generic_write_bulk_callback - port 0
drivers/usb/serial/generic.c: usb_serial_generic_write_start - starting IO
qcserial ttyUSB0: usb_serial_generic_write_start - length = 512, data = 01 00 a0 e1 60 07 00 ea 00 00 9f e5 37 07 00 ea 54 60 01 b0 04 e0 2d e5 20 30 9f e5 04 d0 4d e2 00 10 a0 e1 0d 20 a0 e1 00 00 93 e5 01 1b 00 eb 00 00 50 e3 00 00 e0 13 04 d0 8d e2 00 80 bd e8 3c 70 01 b0 01 00 12 e3 70 40 2d e9 02 40 a0 e1 00 50 a0 e1 01 60 a0 e1 25 00 00 0a 20 40 85 e5 fc 00 9f e5 06 10 a0 e1 1b f7 ff eb 01 00 70 e3 08 00 85 e5 70 80 bd 08 06 30 80 e0 01 20 43 e2 10 40 14 e2 0c 20 85 e5 13 00 00 1a 00 10 a0 e1 d0 00 9f e5 7a f7 ff eb 00 00 50 e3 2a 00 00 0a ff 34 a0 e3 f0 2f 93 e5 05 10 a0 e1 00 00 92 e5 07 20 a0 e3 81 fe ff eb 00 00 50 e3 1c 00 00 1a 0c 30 85 e2 0c 00 13 e8 02 20 43 e0 04 10 a0 e1 01 20 82 e2 08 00 95 e5 78 12 00 eb 05 00 a0 e1 cb ff ff eb 00 40 50 e2 07 00 00 1a 04 00 a0 e1 70 80 bd e8 70 00 9f e5 70 10 9f e5 70 20 9f e5 9d 30 a0 e3 da 11 00 eb d3 ff ff ea 08 10 85 e2 06 00 91 e8 48 00 9f e5 53 f6 ff eb 0c 20 95 e5 40 00 9f e5 08 10 95 e5 31 f7 ff eb 04 00 a0 e1 70 80 bd e8 3c 00 9f e5 30 10 9f e5 30 20 9f e5 af 30 a0 e3 ca 11 00 eb dc ff ff ea 10 00 9f e5 08 10 85 e2 06 00 91 e8 43 f6 ff eb 00 00 e0 e3 70 80 bd e8 00 b0 01 b0 00 80 01 b0 10 ca 00 b0 24 ca 00 b0 94 c9 00 b0 54 c6 00 b0 02 00 13 e3 f0 41 2d e9 03 70 a0 e1 00 60 a0 e1 01 40 a0 e1 02 50 a0 e1 15 00 00 0a 04 30 85 e0 01 40 43 e2 20 70 86 e5 08 50 86 e5 0c 40 86 e5 06 00 a0 e1 97 ff ff eb 00 80 50 e2 08 00 a0 11 f0 81 bd 18 04 20 a0 e1 c4 00 9f e5 05 10 a0 e1 54 f7 ff eb 04 20 a0 e1 05 10 a0 e1 b4 00 9f e5 50 f7 ff eb 10 40 17 e2 07 00 00 0a 08 00 a0 e1 f0 81 bd e8 a0 00 9f e5 a0 10 9f e5 a0 20 9f e5 c3 30 a0 e3 
drivers/usb/serial/usb-serial.c: usb_serial_port_work - port 0
drivers/usb/serial/usb-serial.c: serial_write - port 0, 2048 byte(s)
drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 2048 bytes
drivers/usb/serial/generic.c: usb_serial_generic_write - put 512 bytes into fifo
drivers/usb/serial/usb-serial.c: serial_write - port 0, 1536 byte(s)
drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 1536 bytes
drivers/usb/serial/generic.c: usb_serial_generic_write - put 0 bytes into fifo
drivers/usb/serial/generic.c: usb_serial_generic_write - FIFO is full



-- 
Matthew Garrett | mjg59@srcf.ucam.org

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Matthew Garrett]

Full log is at http://www.codon.org.uk/~mjg59/gobi_log.gz

-- 
Matthew Garrett | mjg59@srcf.ucam.org

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Oliver Neukum]

Am Freitag, 5. Februar 2010 20:58:17 schrieb Matthew Garrett:
> drivers/usb/serial/usb-serial.c: usb_serial_port_work - port 0
> drivers/usb/serial/usb-serial.c: serial_write - port 0, 2048 byte(s)
> drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 2048 bytes
> drivers/usb/serial/generic.c: usb_serial_generic_write - put 512 bytes into fifo
> drivers/usb/serial/usb-serial.c: serial_write - port 0, 1536 byte(s)
> drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 1536 bytes
> drivers/usb/serial/generic.c: usb_serial_generic_write - put 0 bytes into fifo
> drivers/usb/serial/generic.c: usb_serial_generic_write - FIFO is full

OK, could you also get an usbmon trace? This would allow a determination
whether the submitted URB doesn't finish for some reason, or whether
no URB is submitted, possibly because a wakeup is missed.

	Regards
		Oliver

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Oliver Neukum]

Am Freitag, 5. Februar 2010 22:35:55 schrieb Matthew Garrett:
> Full log is at http://www.codon.org.uk/~mjg59/gobi_log.gz

I'm getting a 404.

	Regards
		Oliver

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Anssi Hannula]

On 05.02.2010 23:59, Oliver Neukum wrote:
> Am Freitag, 5. Februar 2010 20:58:17 schrieb Matthew Garrett:
>> drivers/usb/serial/usb-serial.c: usb_serial_port_work - port 0
>> drivers/usb/serial/usb-serial.c: serial_write - port 0, 2048 byte(s)
>> drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 2048 bytes
>> drivers/usb/serial/generic.c: usb_serial_generic_write - put 512 bytes into fifo
>> drivers/usb/serial/usb-serial.c: serial_write - port 0, 1536 byte(s)
>> drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 1536 bytes
>> drivers/usb/serial/generic.c: usb_serial_generic_write - put 0 bytes into fifo
>> drivers/usb/serial/generic.c: usb_serial_generic_write - FIFO is full
> 
> OK, could you also get an usbmon trace? This would allow a determination
> whether the submitted URB doesn't finish for some reason, or whether
> no URB is submitted, possibly because a wakeup is missed.

I'm also affected by this regression. Here's an usbmon trace of
gobi_loader hanging:
http://stuff.onse.fi/gobi2000/gobi-regression.mon.log

-- 
Anssi Hannula

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Alan Stern]

On Sat, 13 Feb 2010, Anssi Hannula wrote:

> On 05.02.2010 23:59, Oliver Neukum wrote:
> > Am Freitag, 5. Februar 2010 20:58:17 schrieb Matthew Garrett:
> >> drivers/usb/serial/usb-serial.c: usb_serial_port_work - port 0
> >> drivers/usb/serial/usb-serial.c: serial_write - port 0, 2048 byte(s)
> >> drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 2048 bytes
> >> drivers/usb/serial/generic.c: usb_serial_generic_write - put 512 bytes into fifo
> >> drivers/usb/serial/usb-serial.c: serial_write - port 0, 1536 byte(s)
> >> drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 1536 bytes
> >> drivers/usb/serial/generic.c: usb_serial_generic_write - put 0 bytes into fifo
> >> drivers/usb/serial/generic.c: usb_serial_generic_write - FIFO is full
> > 
> > OK, could you also get an usbmon trace? This would allow a determination
> > whether the submitted URB doesn't finish for some reason, or whether
> > no URB is submitted, possibly because a wakeup is missed.
> 
> I'm also affected by this regression. Here's an usbmon trace of
> gobi_loader hanging:
> http://stuff.onse.fi/gobi2000/gobi-regression.mon.log

That's odd.  The log shows the final bulk-OUT transfer was cancelled 
after less than 1 ms.  Is there a timeout value somewhere that is too 
small by a factor of 1000?

Alan Stern

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Oliver Neukum]

Am Samstag, 13. Februar 2010 03:50:04 schrieb Alan Stern:
> On Sat, 13 Feb 2010, Anssi Hannula wrote:
> 
> > On 05.02.2010 23:59, Oliver Neukum wrote:
> > > Am Freitag, 5. Februar 2010 20:58:17 schrieb Matthew Garrett:
> > >> drivers/usb/serial/usb-serial.c: usb_serial_port_work - port 0
> > >> drivers/usb/serial/usb-serial.c: serial_write - port 0, 2048 byte(s)
> > >> drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 2048 bytes
> > >> drivers/usb/serial/generic.c: usb_serial_generic_write - put 512 bytes into fifo
> > >> drivers/usb/serial/usb-serial.c: serial_write - port 0, 1536 byte(s)
> > >> drivers/usb/serial/generic.c: usb_serial_generic_write - port 0, 1536 bytes
> > >> drivers/usb/serial/generic.c: usb_serial_generic_write - put 0 bytes into fifo
> > >> drivers/usb/serial/generic.c: usb_serial_generic_write - FIFO is full
> > > 
> > > OK, could you also get an usbmon trace? This would allow a determination
> > > whether the submitted URB doesn't finish for some reason, or whether
> > > no URB is submitted, possibly because a wakeup is missed.
> > 
> > I'm also affected by this regression. Here's an usbmon trace of
> > gobi_loader hanging:
> > http://stuff.onse.fi/gobi2000/gobi-regression.mon.log
> 
> That's odd.  The log shows the final bulk-OUT transfer was cancelled 
> after less than 1 ms.  Is there a timeout value somewhere that is too 
> small by a factor of 1000?

Neither qcserial nor usb-serial implement timeouts.
Is it possible that this is caused by user space closing the handle
causing usb-serial::port_release() to call kill_traffic()?

Anssi, going by your log the last write is quite short and begins
with 342d3030 39202020 20202020 20202020 801d9b80 02000000 3512dcfe 44313032.
Does this match with the last part of the firmware you are transfering?
Could you put an "mdelay(500);" at the beginning of usb-serial::port_release()
and retest?

	Regards
		Oliver

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Anssi Hannula]

On lauantai 13 helmikuu 2010 09:11:36 Oliver Neukum wrote:
> Am Samstag, 13. Februar 2010 03:50:04 schrieb Alan Stern:
> > On Sat, 13 Feb 2010, Anssi Hannula wrote:
> > > On 05.02.2010 23:59, Oliver Neukum wrote:
> > > > Am Freitag, 5. Februar 2010 20:58:17 schrieb Matthew Garrett:
> > > >> drivers/usb/serial/usb-serial.c: usb_serial_port_work - port 0
> > > >> drivers/usb/serial/usb-serial.c: serial_write - port 0, 2048 byte(s)
> > > >> drivers/usb/serial/generic.c: usb_serial_generic_write - port 0,
> > > >> 2048 bytes drivers/usb/serial/generic.c: usb_serial_generic_write -
> > > >> put 512 bytes into fifo drivers/usb/serial/usb-serial.c:
> > > >> serial_write - port 0, 1536 byte(s) drivers/usb/serial/generic.c:
> > > >> usb_serial_generic_write - port 0, 1536 bytes
> > > >> drivers/usb/serial/generic.c: usb_serial_generic_write - put 0
> > > >> bytes into fifo drivers/usb/serial/generic.c:
> > > >> usb_serial_generic_write - FIFO is full
> > > > 
> > > > OK, could you also get an usbmon trace? This would allow a
> > > > determination whether the submitted URB doesn't finish for some
> > > > reason, or whether no URB is submitted, possibly because a wakeup is
> > > > missed.
> > > 
> > > I'm also affected by this regression. Here's an usbmon trace of
> > > gobi_loader hanging:
> > > http://stuff.onse.fi/gobi2000/gobi-regression.mon.log
> > 
> > That's odd.  The log shows the final bulk-OUT transfer was cancelled
> > after less than 1 ms.  Is there a timeout value somewhere that is too
> > small by a factor of 1000?
> 
> Neither qcserial nor usb-serial implement timeouts.
> Is it possible that this is caused by user space closing the handle
> causing usb-serial::port_release() to call kill_traffic()?
> 
> Anssi, going by your log the last write is quite short and begins
> with 342d3030 39202020 20202020 20202020 801d9b80 02000000 3512dcfe
> 44313032. Does this match with the last part of the firmware you are
> transfering?

Yes. (there are three files, this is the last part of the third file)

> Could you put an "mdelay(500);" at the beginning of
> usb-serial::port_release() and retest?

It seems I can't get that far anymore, it hangs much more early now:
http://stuff.onse.fi/gobi2000/gobi-regression2.mon.log
After interrupting gobi_loader I get a WARNING:
http://stuff.onse.fi/gobi2000/gobi-regression2.warning.log
Trying gobi_loader again immediately, the log is almost empty:
http://stuff.onse.fi/gobi2000/gobi-regression3.mon.log
After reboot I get a similar log as regression2:
http://stuff.onse.fi/gobi2000/gobi-regression4.mon.log

Actually, just now I noticed that the first time I had some extra sleep calls 
before starting the firmware upload in gobi_loader, which caused it to 
successfully finish (i.e. not hang; I guess somehow I didn't notice it when I 
logged the first usbmon.log), but the firmware wasn't still uploaded properly 
(that'd be because of the cancelled transfer I guess).

I'll get back to this later today, including testing with mdelay in 
port_release with the extra sleep calls in gobi_loader.

-- 
Anssi Hannula

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Anssi Hannula]

On lauantai 13 helmikuu 2010 15:35:41 Anssi Hannula wrote:
> On lauantai 13 helmikuu 2010 09:11:36 Oliver Neukum wrote:
> > Am Samstag, 13. Februar 2010 03:50:04 schrieb Alan Stern:
> > > On Sat, 13 Feb 2010, Anssi Hannula wrote:
> > > > On 05.02.2010 23:59, Oliver Neukum wrote:
> > > > > Am Freitag, 5. Februar 2010 20:58:17 schrieb Matthew Garrett:
> > > > >> drivers/usb/serial/usb-serial.c: usb_serial_port_work - port 0
> > > > >> drivers/usb/serial/usb-serial.c: serial_write - port 0, 2048
> > > > >> byte(s) drivers/usb/serial/generic.c: usb_serial_generic_write -
> > > > >> port 0, 2048 bytes drivers/usb/serial/generic.c:
> > > > >> usb_serial_generic_write - put 512 bytes into fifo
> > > > >> drivers/usb/serial/usb-serial.c:
> > > > >> serial_write - port 0, 1536 byte(s) drivers/usb/serial/generic.c:
> > > > >> usb_serial_generic_write - port 0, 1536 bytes
> > > > >> drivers/usb/serial/generic.c: usb_serial_generic_write - put 0
> > > > >> bytes into fifo drivers/usb/serial/generic.c:
> > > > >> usb_serial_generic_write - FIFO is full
> > > > > 
> > > > > OK, could you also get an usbmon trace? This would allow a
> > > > > determination whether the submitted URB doesn't finish for some
> > > > > reason, or whether no URB is submitted, possibly because a wakeup
> > > > > is missed.
> > > > 
> > > > I'm also affected by this regression. Here's an usbmon trace of
> > > > gobi_loader hanging:
> > > > http://stuff.onse.fi/gobi2000/gobi-regression.mon.log
> > > 
> > > That's odd.  The log shows the final bulk-OUT transfer was cancelled
> > > after less than 1 ms.  Is there a timeout value somewhere that is too
> > > small by a factor of 1000?
> > 
> > Neither qcserial nor usb-serial implement timeouts.
> > Is it possible that this is caused by user space closing the handle
> > causing usb-serial::port_release() to call kill_traffic()?
> > 
> > Anssi, going by your log the last write is quite short and begins
> > with 342d3030 39202020 20202020 20202020 801d9b80 02000000 3512dcfe
> > 44313032. Does this match with the last part of the firmware you are
> > transfering?
> 
> Yes. (there are three files, this is the last part of the third file)
> 
> > Could you put an "mdelay(500);" at the beginning of
> > usb-serial::port_release() and retest?
> 
> It seems I can't get that far anymore, it hangs much more early now:
> http://stuff.onse.fi/gobi2000/gobi-regression2.mon.log
> After interrupting gobi_loader I get a WARNING:
> http://stuff.onse.fi/gobi2000/gobi-regression2.warning.log
> Trying gobi_loader again immediately, the log is almost empty:
> http://stuff.onse.fi/gobi2000/gobi-regression3.mon.log
> After reboot I get a similar log as regression2:
> http://stuff.onse.fi/gobi2000/gobi-regression4.mon.log
> 
> Actually, just now I noticed that the first time I had some extra sleep
> calls before starting the firmware upload in gobi_loader, which caused it
> to successfully finish (i.e. not hang; I guess somehow I didn't notice it
> when I logged the first usbmon.log), but the firmware wasn't still
> uploaded properly (that'd be because of the cancelled transfer I guess).
> 
> I'll get back to this later today, including testing with mdelay in
> port_release with the extra sleep calls in gobi_loader.

port_release is only called when the serial device is removed, so this has no 
effect here.

-- 
Anssi Hannula

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Oliver Neukum]

Am Samstag, 13. Februar 2010 20:01:54 schrieb Anssi Hannula:
> > I'll get back to this later today, including testing with mdelay in
> > port_release with the extra sleep calls in gobi_loader.
> 
> port_release is only called when the serial device is removed, so this has no 
> effect here.

But something must kill your last URB.
You are not using autosuspend are you? Can load usbserial with "debug=1"?

	Regards
		Oliver

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Anssi Hannula]

On maanantai 15 helmikuu 2010 15:08:27 Oliver Neukum wrote:
> Am Samstag, 13. Februar 2010 20:01:54 schrieb Anssi Hannula:
> > > I'll get back to this later today, including testing with mdelay in
> > > port_release with the extra sleep calls in gobi_loader.
> > 
> > port_release is only called when the serial device is removed, so this
> > has no effect here.
> 
> But something must kill your last URB.
> You are not using autosuspend are you?

Don't know, usbcore has autosuspend=2 and the gobi device has autosuspend=2 
and supports_autosuspend=1.

> Can load usbserial with "debug=1"?

Here's the end of dmesg when running with that option:
http://stuff.onse.fi/gobi2000/gobi-regression.dmesg.log

This is again with the gobi_loader with extra sleep added in the beginning. 
Otherwise it hangs (which is the actual original problem).

-- 
Anssi Hannula

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Oliver Neukum]

Am Samstag, 20. Februar 2010 17:03:41 schrieb Anssi Hannula:
> > But something must kill your last URB.
> > You are not using autosuspend are you?
> 
> Don't know, usbcore has autosuspend=2 and the gobi device has autosuspend=2 
> and supports_autosuspend=1.

What is the content of "level"?

> > Can load usbserial with "debug=1"?
> 
> Here's the end of dmesg when running with that option:
> http://stuff.onse.fi/gobi2000/gobi-regression.dmesg.log
> 
> This is again with the gobi_loader with extra sleep added in the beginning. 
> Otherwise it hangs (which is the actual original problem).

That log makes sure that the final cancellation comes from closing
the file. Is that a log of a working run?

	Regards
		Oliver

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Alan Stern]

On Sat, 20 Feb 2010, Oliver Neukum wrote:

> Am Samstag, 20. Februar 2010 17:03:41 schrieb Anssi Hannula:
> > > But something must kill your last URB.
> > > You are not using autosuspend are you?
> > 
> > Don't know, usbcore has autosuspend=2 and the gobi device has autosuspend=2 
> > and supports_autosuspend=1.
> 
> What is the content of "level"?
> 
> > > Can load usbserial with "debug=1"?
> > 
> > Here's the end of dmesg when running with that option:
> > http://stuff.onse.fi/gobi2000/gobi-regression.dmesg.log
> > 
> > This is again with the gobi_loader with extra sleep added in the beginning. 
> > Otherwise it hangs (which is the actual original problem).
> 
> That log makes sure that the final cancellation comes from closing
> the file. Is that a log of a working run?

Could this simply be one of those cases where the device file is closed 
just after the final write URB is submitted but before it can complete, 
so the URB gets cancelled and the data isn't transferred?

Alan Stern

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Anssi Hannula]

On lauantai 20 helmikuu 2010 20:19:10 Oliver Neukum wrote:
> Am Samstag, 20. Februar 2010 17:03:41 schrieb Anssi Hannula:
> > > But something must kill your last URB.
> > > You are not using autosuspend are you?
> > 
> > Don't know, usbcore has autosuspend=2 and the gobi device has
> > autosuspend=2 and supports_autosuspend=1.
> 
> What is the content of "level"?

"on"

> > > Can load usbserial with "debug=1"?
> > 
> > Here's the end of dmesg when running with that option:
> > http://stuff.onse.fi/gobi2000/gobi-regression.dmesg.log
> > 
> > This is again with the gobi_loader with extra sleep added in the
> > beginning. Otherwise it hangs (which is the actual original problem).
> 
> That log makes sure that the final cancellation comes from closing
> the file. Is that a log of a working run?

No.

-- 
Anssi Hannula

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Anssi Hannula]

On sunnuntai 21 helmikuu 2010 23:28:54 Alan Stern wrote:
> On Sat, 20 Feb 2010, Oliver Neukum wrote:
> > Am Samstag, 20. Februar 2010 17:03:41 schrieb Anssi Hannula:
> > > > Can load usbserial with "debug=1"?
> > > 
> > > Here's the end of dmesg when running with that option:
> > > http://stuff.onse.fi/gobi2000/gobi-regression.dmesg.log
> > > 
> > > This is again with the gobi_loader with extra sleep added in the
> > > beginning. Otherwise it hangs (which is the actual original problem).
> > 
> > That log makes sure that the final cancellation comes from closing
> > the file. Is that a log of a working run?
> 
> Could this simply be one of those cases where the device file is closed
> just after the final write URB is submitted but before it can complete,
> so the URB gets cancelled and the data isn't transferred?

Seems so. I don't think that is the expected behaviour though (and of course 
it used to work).

And of course this doesn't explain why it hangs (and the WARNING) if I remove 
the sleep calls I added in gobi_loader.

-- 
Anssi Hannula

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Oliver Neukum]

Am Sonntag, 21. Februar 2010 22:28:54 schrieb Alan Stern:
> > > This is again with the gobi_loader with extra sleep added in the beginning. 
> > > Otherwise it hangs (which is the actual original problem).
> > 
> > That log makes sure that the final cancellation comes from closing
> > the file. Is that a log of a working run?
> 
> Could this simply be one of those cases where the device file is closed 
> just after the final write URB is submitted but before it can complete, 
> so the URB gets cancelled and the data isn't transferred?

It looks likely, but why doesn't a delay fix it?

	Regards
		Oliver

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Oliver Neukum]

Am Sonntag, 21. Februar 2010 22:42:12 schrieb Anssi Hannula:
> And of course this doesn't explain why it hangs (and the WARNING) if I remove 
> the sleep calls I added in gobi_loader.

Please tell us where you put a delay.

	Regards
		Oliver

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Anssi Hannula]

On maanantai 22 helmikuu 2010 00:12:36 Oliver Neukum wrote:
> Am Sonntag, 21. Februar 2010 22:42:12 schrieb Anssi Hannula:
> > And of course this doesn't explain why it hangs (and the WARNING) if I
> > remove the sleep calls I added in gobi_loader.
> 
> Please tell us where you put a delay.

As I said earlier, the delay was put *before* most of the data gets written.

More specifically, I inserted a delay of one second between transmission of 
magic1 and magic2, one between magic2 and magic3, and one between magic3 and 
the first firmware file.

If I additionally insert a one-second delay before the fd is closed, I get 
this usbmon log:
http://stuff.onse.fi/gobi2000/gobi-regression5.mon.log

The firmware upload is still unsuccessful.

-- 
Anssi Hannula

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Anssi Hannula]

On maanantai 22 helmikuu 2010 01:06:36 Anssi Hannula wrote:
> On maanantai 22 helmikuu 2010 00:12:36 Oliver Neukum wrote:
> > Am Sonntag, 21. Februar 2010 22:42:12 schrieb Anssi Hannula:
> > > And of course this doesn't explain why it hangs (and the WARNING) if I
> > > remove the sleep calls I added in gobi_loader.
> > 
> > Please tell us where you put a delay.
> 
> As I said earlier, the delay was put *before* most of the data gets
> written.
> 
> More specifically, I inserted a delay of one second between transmission of
> magic1 and magic2, one between magic2 and magic3, and one between magic3
> and the first firmware file.
> 
> If I additionally insert a one-second delay before the fd is closed, I get
> this usbmon log:
> http://stuff.onse.fi/gobi2000/gobi-regression5.mon.log
> 
> The firmware upload is still unsuccessful.

If I use the option driver instead of qcserial, the firmware upload is always 
successful (without any added delays needed). The usbmon log for that case can 
be found here:
http://stuff.onse.fi/gobi2000/gobi-regression6.mon.log

-- 
Anssi Hannula

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Anssi Hannula]

On maanantai 22 helmikuu 2010 01:13:35 Anssi Hannula wrote:
> On maanantai 22 helmikuu 2010 01:06:36 Anssi Hannula wrote:
> > On maanantai 22 helmikuu 2010 00:12:36 Oliver Neukum wrote:
> > > Am Sonntag, 21. Februar 2010 22:42:12 schrieb Anssi Hannula:
> > > > And of course this doesn't explain why it hangs (and the WARNING) if
> > > > I remove the sleep calls I added in gobi_loader.
> > > 
> > > Please tell us where you put a delay.
> > 
> > As I said earlier, the delay was put *before* most of the data gets
> > written.
> > 
> > More specifically, I inserted a delay of one second between transmission
> > of magic1 and magic2, one between magic2 and magic3, and one between
> > magic3 and the first firmware file.
> > 
> > If I additionally insert a one-second delay before the fd is closed, I
> > get this usbmon log:
> > http://stuff.onse.fi/gobi2000/gobi-regression5.mon.log
> > 
> > The firmware upload is still unsuccessful.
> 
> If I use the option driver instead of qcserial, the firmware upload is
> always successful (without any added delays needed). The usbmon log for
> that case can be found here:
> http://stuff.onse.fi/gobi2000/gobi-regression6.mon.log

I installed 2.6.31.12 to get a usbmon log with qcserial before the regression 
as well (without delays, upload successful):
http://stuff.onse.fi/gobi2000/gobi-regression7.mon.log

-- 
Anssi Hannula

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Alan Stern]

On Mon, 22 Feb 2010, Anssi Hannula wrote:

> > > If I additionally insert a one-second delay before the fd is closed, I
> > > get this usbmon log:
> > > http://stuff.onse.fi/gobi2000/gobi-regression5.mon.log
> > > 
> > > The firmware upload is still unsuccessful.
> > 
> > If I use the option driver instead of qcserial, the firmware upload is
> > always successful (without any added delays needed). The usbmon log for
> > that case can be found here:
> > http://stuff.onse.fi/gobi2000/gobi-regression6.mon.log
> 
> I installed 2.6.31.12 to get a usbmon log with qcserial before the regression 
> as well (without delays, upload successful):
> http://stuff.onse.fi/gobi2000/gobi-regression7.mon.log

The major difference between the logs is in the way the data get
divided up into packets.  In both the successful logs, there are 
sequences of bulk-OUT packets with lengths like:

	44, 1, 15, 1, 13

where the unsuccessful transfer just has a single packet of length 74.  
Also, the successful transfers show a lot of bulk-IN traffic where the 
unsuccessful transfer doesn't have any.  I don't know if that is 
relevant, however.

No other differences stand out.

Alan Stern

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Anssi Hannula]

On maanantai 22 helmikuu 2010 17:28:36 Alan Stern wrote:
> On Mon, 22 Feb 2010, Anssi Hannula wrote:
> > > > If I additionally insert a one-second delay before the fd is closed,
> > > > I get this usbmon log:
> > > > http://stuff.onse.fi/gobi2000/gobi-regression5.mon.log
> > > > 
> > > > The firmware upload is still unsuccessful.
> > > 
> > > If I use the option driver instead of qcserial, the firmware upload is
> > > always successful (without any added delays needed). The usbmon log for
> > > that case can be found here:
> > > http://stuff.onse.fi/gobi2000/gobi-regression6.mon.log
> > 
> > I installed 2.6.31.12 to get a usbmon log with qcserial before the
> > regression as well (without delays, upload successful):
> > http://stuff.onse.fi/gobi2000/gobi-regression7.mon.log
> 
> The major difference between the logs is in the way the data get
> divided up into packets.  In both the successful logs, there are
> sequences of bulk-OUT packets with lengths like:
> 
> 	44, 1, 15, 1, 13
> 
> where the unsuccessful transfer just has a single packet of length 74.
> Also, the successful transfers show a lot of bulk-IN traffic where the
> unsuccessful transfer doesn't have any.  I don't know if that is
> relevant, however.
> 
> No other differences stand out.

I guess that would suggest that the device doesn't allow the initialization 
data to be broken into packets arbitrarily (though some differences seem 
allowed, as the windows driver transmits them differently).

Does this mean a tty interface is ill-suited for the microcode upload, and 
instead qcserial should use the kernel's generic microcode upload mechanism or 
the userspace should use libusb to do it?

Any idea what could be causing the hang, then? The WARNING that appears when 
interrupting the hung gobi_loader is for serial_unthrottle() being called 
while usb_serial_port->port.count == 0.

-- 
Anssi Hannula

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Alan Stern]

On Mon, 22 Feb 2010, Anssi Hannula wrote:

> I guess that would suggest that the device doesn't allow the initialization 
> data to be broken into packets arbitrarily (though some differences seem 
> allowed, as the windows driver transmits them differently).
> 
> Does this mean a tty interface is ill-suited for the microcode upload, and 
> instead qcserial should use the kernel's generic microcode upload mechanism or 
> the userspace should use libusb to do it?

I don't know.  Didn't the old successful code use a tty interface?

> Any idea what could be causing the hang, then?

No idea, unless it's the device.

>  The WARNING that appears when 
> interrupting the hung gobi_loader is for serial_unthrottle() being called 
> while usb_serial_port->port.count == 0.

That's a bogus warning.  It will be removed in an upcoming kernel 
version.

Alan Stern

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Matthew Garrett]

On Mon, Feb 22, 2010 at 02:10:33PM -0500, Alan Stern wrote:
> On Mon, 22 Feb 2010, Anssi Hannula wrote:
> > Does this mean a tty interface is ill-suited for the microcode upload, and 
> > instead qcserial should use the kernel's generic microcode upload mechanism or 
> > the userspace should use libusb to do it?
> 
> I don't know.  Didn't the old successful code use a tty interface?

Yes. The kfifo changes have caused some sort of alteration in behaviour.

> > Any idea what could be causing the hang, then?
> 
> No idea, unless it's the device.

Once the device hangs, it then tends to refuse any input until power 
cycled. So it's clearly getting into some sort of undefined state, 
though whether that's because it only gets sent half of its firmware 
(ie, the hang occurs and as a result the hardware dies) or whether it's 
causing the hang by dying is unclear.

-- 
Matthew Garrett | mjg59@srcf.ucam.org

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Anssi Hannula]

On maanantai 22 helmikuu 2010 21:10:33 Alan Stern wrote:
> On Mon, 22 Feb 2010, Anssi Hannula wrote:
> > I guess that would suggest that the device doesn't allow the
> > initialization data to be broken into packets arbitrarily (though some
> > differences seem allowed, as the windows driver transmits them
> > differently).
> > 
> > Does this mean a tty interface is ill-suited for the microcode upload,
> > and instead qcserial should use the kernel's generic microcode upload
> > mechanism or the userspace should use libusb to do it?
> 
> I don't know.  Didn't the old successful code use a tty interface?

Yes, but does the tty interface guarantee that the data of one write call is 
sent as one packet to the device?

If I understood this correctly, it seems the changes have caused it to now 
concatenate short writes into one packet, which the device doesn't seem to 
like.

-- 
Anssi Hannula

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Alan Stern]

On Mon, 22 Feb 2010, Anssi Hannula wrote:

> On maanantai 22 helmikuu 2010 21:10:33 Alan Stern wrote:
> > On Mon, 22 Feb 2010, Anssi Hannula wrote:
> > > I guess that would suggest that the device doesn't allow the
> > > initialization data to be broken into packets arbitrarily (though some
> > > differences seem allowed, as the windows driver transmits them
> > > differently).
> > > 
> > > Does this mean a tty interface is ill-suited for the microcode upload,
> > > and instead qcserial should use the kernel's generic microcode upload
> > > mechanism or the userspace should use libusb to do it?
> > 
> > I don't know.  Didn't the old successful code use a tty interface?
> 
> Yes, but does the tty interface guarantee that the data of one write call is 
> sent as one packet to the device?

Not as far as I know.

> If I understood this correctly, it seems the changes have caused it to now 
> concatenate short writes into one packet, which the device doesn't seem to 
> like.

That seems to be the most likely explanation.  You might be able to
test it by adding some delays to the driver between those short writes,
so they don't get concatenated.

Alan Stern

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Alan Stern]

On Mon, 22 Feb 2010, Matthew Garrett wrote:

> On Mon, Feb 22, 2010 at 02:10:33PM -0500, Alan Stern wrote:
> > On Mon, 22 Feb 2010, Anssi Hannula wrote:
> > > Does this mean a tty interface is ill-suited for the microcode upload, and 
> > > instead qcserial should use the kernel's generic microcode upload mechanism or 
> > > the userspace should use libusb to do it?
> > 
> > I don't know.  Didn't the old successful code use a tty interface?
> 
> Yes. The kfifo changes have caused some sort of alteration in behaviour.
> 
> > > Any idea what could be causing the hang, then?
> > 
> > No idea, unless it's the device.
> 
> Once the device hangs, it then tends to refuse any input until power 
> cycled. So it's clearly getting into some sort of undefined state, 
> though whether that's because it only gets sent half of its firmware 
> (ie, the hang occurs and as a result the hardware dies) or whether it's 
> causing the hang by dying is unclear.

The latest logs did show all the firmware getting sent -- or at least, 
they show that as much data was sent by the nonworking driver as by the 
working driver.  So I'd say the device causes the hang by dying, 
although I don't know where the hang is or why a dead device should 
cause it.

Alan Stern

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Matthew Garrett]

On Mon, Feb 22, 2010 at 09:24:58PM +0000, Alan Cox wrote:

> If the device wants exactly bounded packets then for the firmware loader
> tty is probably the wrong interface.

Upstream's driver is tty based, so it's not really clear what the 
hardware expects.

-- 
Matthew Garrett | mjg59@srcf.ucam.org

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Alan Cox]

> Yes, but does the tty interface guarantee that the data of one write call is 
> sent as one packet to the device?

Not usually but it can do. At least the core tty code supports this for
suitable ldiscs.

> If I understood this correctly, it seems the changes have caused it to now 
> concatenate short writes into one packet, which the device doesn't seem to 
> like.

If the device wants exactly bounded packets then for the firmware loader
tty is probably the wrong interface.

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Oliver Neukum]

Am Montag, 22. Februar 2010 19:35:35 schrieb Anssi Hannula:
> On maanantai 22 helmikuu 2010 17:28:36 Alan Stern wrote:

> > The major difference between the logs is in the way the data get
> > divided up into packets.  In both the successful logs, there are
> > sequences of bulk-OUT packets with lengths like:
> > 
> > 	44, 1, 15, 1, 13
> > 
> > where the unsuccessful transfer just has a single packet of length 74.
> > Also, the successful transfers show a lot of bulk-IN traffic where the
> > unsuccessful transfer doesn't have any.  I don't know if that is
> > relevant, however.
> > 
> > No other differences stand out.
> 
> I guess that would suggest that the device doesn't allow the initialization 
> data to be broken into packets arbitrarily (though some differences seem 
> allowed, as the windows driver transmits them differently).

Hi,

let's try testing this hypothesis. Can you change the following line in
usb_serial_probe():
		if (kfifo_alloc(&port->write_fifo, PAGE_SIZE, GFP_KERNEL))
			goto probe_error;

to:

		if (kfifo_alloc(&port->write_fifo, 64, GFP_KERNEL))
			goto probe_error;

This may shed some light on the behavior.

	Regards
		Oliver

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Anssi Hannula]

On tiistai 23 helmikuu 2010 01:26:02 Oliver Neukum wrote:
> Am Montag, 22. Februar 2010 19:35:35 schrieb Anssi Hannula:
> > On maanantai 22 helmikuu 2010 17:28:36 Alan Stern wrote:
> > > The major difference between the logs is in the way the data get
> > > divided up into packets.  In both the successful logs, there are
> > > 
> > > sequences of bulk-OUT packets with lengths like:
> > > 	44, 1, 15, 1, 13
> > > 
> > > where the unsuccessful transfer just has a single packet of length 74.
> > > Also, the successful transfers show a lot of bulk-IN traffic where the
> > > unsuccessful transfer doesn't have any.  I don't know if that is
> > > relevant, however.
> > > 
> > > No other differences stand out.
> > 
> > I guess that would suggest that the device doesn't allow the
> > initialization data to be broken into packets arbitrarily (though some
> > differences seem allowed, as the windows driver transmits them
> > differently).
> 
> Hi,
> 
> let's try testing this hypothesis. Can you change the following line in
> usb_serial_probe():
> 		if (kfifo_alloc(&port->write_fifo, PAGE_SIZE, GFP_KERNEL))
> 			goto probe_error;
> 
> to:
> 
> 		if (kfifo_alloc(&port->write_fifo, 64, GFP_KERNEL))
> 			goto probe_error;
> 
> This may shed some light on the behavior.

No effect.

However, I added more sleep(1) calls to gobi_loader, now between every magicX 
string and firmware files (therefore ensuring the data gets flushed to the 
device at those points). Now the upload was successful.

-- 
Anssi Hannula

Re: [REGRESSION] "USB: use kfifo to buffer usb-generic serial writes" causes gobi_loader to hang

[Anssi Hannula]

On maanantai 22 helmikuu 2010 22:12:41 Alan Stern wrote:
> On Mon, 22 Feb 2010, Matthew Garrett wrote:
> > On Mon, Feb 22, 2010 at 02:10:33PM -0500, Alan Stern wrote:
> > > On Mon, 22 Feb 2010, Anssi Hannula wrote:
> > > > Does this mean a tty interface is ill-suited for the microcode
> > > > upload, and instead qcserial should use the kernel's generic
> > > > microcode upload mechanism or the userspace should use libusb to do
> > > > it?
> > > 
> > > I don't know.  Didn't the old successful code use a tty interface?
> > 
> > Yes. The kfifo changes have caused some sort of alteration in behaviour.
> > 
> > > > Any idea what could be causing the hang, then?
> > > 
> > > No idea, unless it's the device.
> > 
> > Once the device hangs, it then tends to refuse any input until power
> > cycled. So it's clearly getting into some sort of undefined state,
> > though whether that's because it only gets sent half of its firmware
> > (ie, the hang occurs and as a result the hardware dies) or whether it's
> > causing the hang by dying is unclear.
> 
> The latest logs did show all the firmware getting sent -- or at least,
> they show that as much data was sent by the nonworking driver as by the
> working driver.  So I'd say the device causes the hang by dying,
> although I don't know where the hang is or why a dead device should
> cause it.

When the hang happens, the complete firmware is *not* sent to the device. The 
usbmon log is 10 times smaller:
http://stuff.onse.fi/gobi2000/gobi-regression2.mon.log
For reference, here's the hang with usbserial debug=1:
http://stuff.onse.fi/gobi2000/gobi-regression2.dmesg.log

The later logs were of runs that did not hang, but did still not work. I added 
descriptions here, in case someone is confused with all the logs (which I 
should've named better): http://stuff.onse.fi/gobi2000/

But if a device in corrupt state can cause such a hang, then it is likely that 
that is happening here (due to the packet bounding issue described in the 
other messages).

-- 
Anssi Hannula