Re: [linux-usb-devel] [2.6.0-test2-bk5] OHCI USB printing call trace...

From: Daniel Blueman (daniel.blueman@gmx.net)
Date: Wed Aug 06 2003 - 17:54:22 EST

Next message: Andrew Morton: "Re: [2.6] system is very slow during disk access"
Previous message: Michael Buesch: "Re: [2.6] system is very slow during disk access"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

Oliver,

Thanks for your response. This is consistently reproducible and the printer
will get to ~20% down the first page before stopping. Just when or after it
stops printing, I observed the system time jump to 61% [2], then some
polling/logging going on, until I turn the printer off or disconnect the cable. This
can be seen again in the logs [1], but we do not observe your additional
debugging. I enabled the additional USB debugging also.

--- [1]
[printer plugged into root hub]
Aug 6 23:42:33 stratum kernel: hub 1-0:0: debounce: port 2: delay 100ms
stable 4 status 0x101
Aug 6 23:42:33 stratum kernel: hub 1-0:0: new USB device on port 2,
assigned address 3
Aug 6 23:42:33 stratum kernel: usb 1-2: Product: USB Printer
Aug 6 23:42:33 stratum kernel: usb 1-2: Manufacturer: EPSON
Aug 6 23:42:33 stratum kernel: usb 1-2: SerialNumber: ABCDE0212160438390
Aug 6 23:42:33 stratum kernel: drivers/usb/class/usblp.c: usblp0: USB
Bidirectional printer dev 3 if 0 alt 0 proto 2 vid 0x04B8 pid 0x0005

[print job started; printer reached 20% down the page and stopped]
Aug 6 23:44:33 stratum kernel: drivers/usb/class/usblp.c: usblp0: error
-110 reading printer status
Aug 6 23:44:33 stratum last message repeated 17 times

[printer powered off]
Aug 6 23:44:33 stratum kernel: usb 1-2: USB disconnect, address 3
Aug 6 23:44:33 stratum kernel: ohci-hcd 0000:00:02.2: ed df122080 (#0)
state 2(has tds)
Aug 6 23:44:33 stratum kernel: drivers/usb/class/usblp.c: usblp0: error
-108 reading printer status
Aug 6 23:44:37 stratum kernel: drivers/usb/class/usblp.c: usblp0: removed
Aug 6 23:44:37 stratum kernel: Unable to handle kernel paging request at
virtual address d6b990e4
Aug 6 23:44:37 stratum kernel: printing eip:
Aug 6 23:44:37 stratum kernel: c02c6383
Aug 6 23:44:37 stratum kernel: *pde = 00059067
Aug 6 23:44:37 stratum kernel: *pte = 16b99000
Aug 6 23:44:37 stratum kernel: Oops: 0000 [#1]
Aug 6 23:44:37 stratum kernel: CPU: 0
Aug 6 23:44:37 stratum kernel: EIP: 0060:[<c02c6383>] Not tainted
Aug 6 23:44:37 stratum kernel: EFLAGS: 00010282
Aug 6 23:44:37 stratum kernel: EIP is at usb_buffer_free+0xd/0x46
Aug 6 23:44:37 stratum kernel: eax: d6b99004 ebx: dda96004 ecx:
df1aa000 edx: d6b70000
Aug 6 23:44:37 stratum kernel: esi: dda96008 edi: dcc6f098 ebp:
d6b71f1c esp: d6b71f0c
Aug 6 23:44:37 stratum kernel: ds: 007b es: 007b ss: 0068
Aug 6 23:44:37 stratum kernel: Process usb (pid: 1257, threadinfo=d6b70000
task=d0fb3000)
Aug 6 23:44:37 stratum kernel: Stack: d6b71f0c dda96004 dda96008 dcc6f098
d6b71f38 c02ddf4d d6b99004 00002000
Aug 6 23:44:37 stratum kernel: d1370000 11370000 dda96004 d6b71f50
c02de04f dda96004 00000077 d113f004
Aug 6 23:44:37 stratum kernel: dffe61dc d6b71f70 c016aa7b dcc6f098
d113f004 dd86d004 d113f004 d1045004
Aug 6 23:44:37 stratum kernel: Call Trace:
Aug 6 23:44:37 stratum kernel: [<c02ddf4d>] usblp_cleanup+0x43/0xa2
Aug 6 23:44:37 stratum kernel: [<c02de04f>] usblp_release+0x6b/0x6d
Aug 6 23:44:37 stratum kernel: [<c016aa7b>] __fput+0xb5/0xc4
Aug 6 23:44:37 stratum kernel: [<c0168c09>] filp_close+0x4b/0x74
Aug 6 23:44:37 stratum kernel: [<c0168d35>] sys_close+0x103/0x226
Aug 6 23:44:37 stratum kernel: [<c0169b05>] sys_read+0x3f/0x5d
Aug 6 23:44:37 stratum kernel: [<c010a07d>] sysenter_past_esp+0x52/0x71
Aug 6 23:44:37 stratum kernel:
Aug 6 23:44:37 stratum kernel: Code: 8b 90 e0 00 00 00 85 d2 74 0e 8b 4a 20
85 c9 74 07 8b 41 18

--- [2]
$ vmstat 1
procs memory swap io system
cpu
r b w swpd free buff cache si so bi bo in cs us sy
id
0 0 0 0 195816 9412 130720 0 0 750 115 1197 469 14 6
80
0 0 0 0 195816 9412 130720 0 0 0 0 1020 48 0 1
99
1 0 0 0 183144 9416 130840 0 0 0 0 1006 408 56 7
37
0 1 0 0 183080 9416 130840 0 0 0 0 1970 1993 61 0
39
1 0 0 0 183080 9424 130840 0 0 0 384 2012 2092 0 8
92
1 0 0 0 183096 9424 130840 0 0 0 0 2018 2044 0 0
100
1 0 0 0 183096 9424 130840 0 0 0 0 2004 2026 1 0
99
1 0 0 0 183096 9424 130840 0 0 0 0 2021 2052 0 0
100
1 0 0 0 183096 9424 130840 0 0 0 0 2005 2022 0 1
99
1 0 0 0 183096 9424 130840 0 0 0 0 2020 2041 0 2
98
1 0 0 0 183096 9432 130840 0 0 0 20 2002 2049 1 5
94
1 0 0 0 183096 9432 130840 0 0 0 0 2020 2034 0 0
100
1 0 0 0 183096 9432 130840 0 0 0 0 2003 2032 0 1
99

> > --- [test print job started]
> >
> > drivers/usb/class/usblp.c: usblp0: nonzero read/write bulk status
> received:
> > -2
> > drivers/usb/class/usblp.c: usblp0: error -110 reading printer status
> > [last message repeated 216 times]
>
> Did it print at all?
> Could you please run this diagnostic patch?
>
> Regards
> Oliver
[snip]
> + printk("Timeout during write to printer.\n");

-- Daniel J Blueman

COMPUTERBILD 15/03: Premium-e-mail-Dienste im Test -------------------------------------------------- 1. GMX TopMail - Platz 1 und Testsieger! 2. GMX ProMail - Platz 2 und Preis-Qualitätssieger! 3. Arcor - 4. web.de - 5. T-Online - 6. freenet.de - 7. daybyday - 8. e-Post

- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/

Next message: Andrew Morton: "Re: [2.6] system is very slow during disk access"
Previous message: Michael Buesch: "Re: [2.6] system is very slow during disk access"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

This archive was generated by hypermail 2b29 : Thu Aug 07 2003 - 22:00:35 EST