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 | [email protected]
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
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
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 | [email protected]
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
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 | [email protected]
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
On Tue, 19 Jan 2010 14:20:29 +0100
Oliver Neukum <[email protected]> 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) ?
Am Dienstag, 19. Januar 2010 14:29:34 schrieb Alan Cox:
> On Tue, 19 Jan 2010 14:20:29 +0100
> Oliver Neukum <[email protected]> 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
On Tue, 19 Jan 2010 14:57:00 +0100
Oliver Neukum <[email protected]> wrote:
> Am Dienstag, 19. Januar 2010 14:29:34 schrieb Alan Cox:
> > On Tue, 19 Jan 2010 14:20:29 +0100
> > Oliver Neukum <[email protected]> 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.
> 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.
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
> > 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
> > > 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...
On Tue, 19 Jan 2010 16:25:36 +0100
Johan Hovold <[email protected]> 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.
Am Dienstag, 19. Januar 2010 17:27:46 schrieb Alan Cox:
> On Tue, 19 Jan 2010 16:25:36 +0100
> Johan Hovold <[email protected]> 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
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 <[email protected]> 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
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 <[email protected]>
> 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 <[email protected]>
> ---
> 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
>
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
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
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 | [email protected]
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
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 | [email protected]
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
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 | [email protected]
Full log is at http://www.codon.org.uk/~mjg59/gobi_log.gz
--
Matthew Garrett | [email protected]
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
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
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
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
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
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
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
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
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
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
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
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
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
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
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
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
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
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
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
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
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
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 | [email protected]
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
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
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
> 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.
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 | [email protected]
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
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
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