Below follows an excerpt of the debug output from scanner.c and uhci-debug.c. To avoid cluttering this mailing list with debug information I have put the complete syslog on the web at http://www.oink-oink-oink.net/usb-problem/syslog2.gz (269 kB).
> > Every time I use my Nikon Coolscan IV LS-40 USB scanner the usb driver > > crashes after scanning a small number of frames with the message: > > What do you mean by crashing? Do you get a kernel oops or does the > kernel freeze? The USB subsystem freezes. Sometimes I can solve it with "rmmod usb-uhci" but usually I have to reboot to get the USB subsystem to work again. The good news is that the part of the system that does not depend on USB keeps running, so I can login on a console and type "reboot". > > Mar 10 03:13:48 kletskop kernel: usb_control/bulk_msg: timeout > > Mar 10 03:13:48 kletskop kernel: scanner.c: write_scanner: NAK received. > > Do you get this message after 60 seconds of "nothing happens"? The > timeout for writing is 60 seconds. Do you know if there is any bulk > write that may take longer with this scanner? You can change the > timeout in the source code (scanner.c) but I don't think that will > help. Search for the function write_scanner and on this function for > result = usb_bulk_msg. Change the last argument from 60*HZ to e.g. > 120*HZ. > > > This is with linux-2.4.20 and in fact it has been a problem with all > > stable linux kernels that I have tried. Kernels <= 2.4.18 would crash > > within a few seconds, while kernels >= 2.4.19 do a decent job until they > > crash after some 10-15 minutes scan time. > > There was no change in the kernel USB scanner driver between 2.4.18 > and 2.4.19. There were some changes for 2.4.20 but I don't think they > could have any influence on the behaviour you noticed. > > You could try 2.4.21-pre5 which has the latest scanner driver with > quite some updates. Please also enable debuging in > drivers/usb/scanner.h (remove the "//2 from #define DEBUG). Please > send me the debugging messages that occure during a failed scan. Did that, the problem persists with 2.4.21-pre5. I changed the timeout in write_scanner to 600*HZ and I enabled debugging. At the end of this mail I am including messages from syslog . > > I am using vuescan which is also available for windows; when booting my > > computer in Windows the exact same hardware runs vuescan without > > problems, so I am assuming it is a problem with the linux usb driver. To > > be sure I have bought a new usb pci card (uhci instead of the > > motherboard ohci) but this did not help. So the problem is with both the > > usb-uhci and usb-ohci module (or something that they share). > > If it's not the scanner driver: USB core or hub driver? Or it's a > problem with vuescan. There may be small timing differences between > Windows and Linux or other hardware oddities that lead to different > behaviour. > > Is the scanner connected to the root hub directly or do you use any > external hubs or a USB extension cable? It is directly connected to one of the three root hubs available on the motherboard. > > I saw a message on this mailing list by Martin Thornquist dated > > 2002-05-30 where he described the same problem. > > In his description the first error occurs in read_scanner not > write_scanner. That error was a "funky result", not a timeout. > > > Could anybody out there > > suggest a remedy? If you need more details, please let me know. > > Which USB transfers cause this problem? Are there any problems with > the read transfers before write? Accoring to the messages below: yes. > Does SANE work instead of vuescan? Or do you get the same timeouts? I > don't know if that's the same scanner but a "Nikon LS 40 ED" is listed > as supported device. You can use current versions of sane with libusb > instead of the kernel scanner driver. If it works with libusb but not > the kernel driver we know who is to blame :-) I downloaded SANE and got the "coolscan2" backend to work with my Nikon LS-40. However, I could not operate it in a way that produced usable pictures, still looking for a GUI frontend that supports coolscan2. I noticed however that typing Ctl-C to the "scanimage" frontend produced the familiar "usb_control/bulk_msg: timeout" messages in the syslog... > Bye, > Henning Thank you for your time! The syslog messages start like this: Mar 18 05:26:32 kletskop kernel: scanner.c: probe_scanner: USB dev address:dc3a8600 Mar 18 05:26:32 kletskop kernel: scanner.c: probe_scanner: ifnum:0 Mar 18 05:26:32 kletskop kernel: scanner.c: probe_scanner: Number of Endpoints:3 Mar 18 05:26:32 kletskop kernel: scanner.c: probe_scanner: bulk_out_ep:1 Mar 18 05:26:32 kletskop kernel: scanner.c: probe_scanner: bulk_in_ep:2 Mar 18 05:26:32 kletskop kernel: scanner.c: probe_scanner: intr_ep:3 Mar 18 05:26:32 kletskop kernel: scanner.c: probe_scanner: Allocated minor:0 Mar 18 05:26:32 kletskop kernel: scanner.c: probe_scanner(0): Address of scn:dfaa6dc0 Mar 18 05:26:32 kletskop kernel: scanner.c: probe_scanner(0): Configuring IRQ handler for intr EP:3 Mar 18 05:26:32 kletskop kernel: scanner.c: probe_scanner(0): obuf address:dc415000 Mar 18 05:26:32 kletskop kernel: scanner.c: probe_scanner(0): ibuf address:d91b0000 Mar 18 05:26:32 kletskop kernel: scanner.c: scanner0: device node registration failed Mar 18 05:26:32 kletskop kernel: scanner.c: USB scanner device (0x04b0/0x4000) now attached to scanner0 Mar 18 05:26:32 kletskop kernel: usb.c: usbscanner driver claimed interface d9200b40 Mar 18 05:26:32 kletskop kernel: usb.c: kusbd: /sbin/hotplug add 2 Mar 18 05:26:32 kletskop kernel: hub.c: port 2, portstatus 100, change 0, 12 Mb/s Mar 18 05:26:32 kletskop /sbin/hotplug: arguments (usb) env (DEVFS=/proc/bus/usb OLDPWD=/ PATH=/bin:/sbin:/usr/sbin:/usr/bin ACTION=add PWD=/etc/hotplug SHLVL=1 HOME=/ DEVICE=/proc/bus/usb/002/002 PRODUCT=4b0/4000/110 TYPE=255/255/255 DEBUG=kernel _=/usr/bin/env) Mar 18 05:26:32 kletskop /sbin/hotplug: invoke /etc/hotplug/usb.agent () Mar 18 05:26:35 kletskop /etc/hotplug/usb.agent: Setup scanner for USB product 4b0/4000/110 Mar 18 05:27:29 kletskop kernel: scanner.c: open_scanner: scn_minor:0 Mar 18 05:27:29 kletskop kernel: scanner.c: write stats(0): result:0 this_write:6 partial:6 Mar 18 05:27:29 kletskop kernel: scanner.c: write stats(0): result:0 this_write:1 partial:1 Mar 18 05:27:29 kletskop kernel: scanner.c: read stats(0): result:0 this_read:1 partial:1 count:1 Mar 18 05:27:29 kletskop kernel: scanner.c: read stats(0): result:0 this_read:36 partial:36 count:36 ...and then many more read stats and write stats. With debugging switched on it took much longer to reach the point of failure (does this indicate the problem is timing-related?). The failure manifests itself first as a "uhci_result_interrupt/bulk() failed with status 500000" message in the syslog, followed by a dump of a "struct uhci_td" linked list: Mar 18 07:02:25 kletskop kernel: scanner.c: write stats(0): result:0 this_write:10 partial:10 Mar 18 07:02:25 kletskop kernel: scanner.c: write stats(0): result:0 this_write:1 partial:1 Mar 18 07:02:25 kletskop kernel: scanner.c: read stats(0): result:0 this_read:1 partial:1 count:1 Mar 18 07:02:25 kletskop kernel: scanner.c: read stats(0): result:0 this_read:32768 partial:21224 count:63672 Mar 18 07:02:25 kletskop kernel: scanner.c: read stats(0): result:0 this_read:30904 partial:21224 count:30904 Mar 18 07:02:25 kletskop kernel: scanner.c: read stats(0): result:0 this_read:21224 partial:21224 count:21224 Mar 18 07:02:25 kletskop kernel: scanner.c: read stats(0): result:0 this_read:8 partial:8 count:8 Mar 18 07:02:25 kletskop kernel: scanner.c: write stats(0): result:0 this_write:10 partial:10 Mar 18 07:02:25 kletskop kernel: scanner.c: write stats(0): result:0 this_write:1 partial:1 Mar 18 07:02:25 kletskop kernel: scanner.c: read stats(0): result:0 this_read:1 partial:1 count:1 Mar 18 07:02:25 kletskop kernel: scanner.c: read stats(0): result:0 this_read:32768 partial:21224 count:63672 Mar 18 07:02:25 kletskop kernel: scanner.c: read stats(0): result:0 this_read:30904 partial:21224 count:30904 Mar 18 07:02:25 kletskop kernel: scanner.c: read stats(0): result:0 this_read:21224 partial:21224 count:21224 Mar 18 07:02:25 kletskop kernel: scanner.c: read stats(0): result:0 this_read:8 partial:8 count:8 Mar 18 07:02:26 kletskop kernel: scanner.c: write stats(0): result:0 this_write:10 partial:10 Mar 18 07:02:26 kletskop kernel: scanner.c: write stats(0): result:0 this_write:1 partial:1 Mar 18 07:02:26 kletskop kernel: scanner.c: read stats(0): result:0 this_read:1 partial:1 count:1 Mar 18 07:02:26 kletskop kernel: scanner.c: read stats(0): result:0 this_read:32768 partial:21224 count:42448 Mar 18 07:02:26 kletskop kernel: uhci.c: uhci_result_interrupt/bulk() failed with status 500000 Mar 18 07:02:26 kletskop kernel: [df4950c0] link (1f495092) element (10e2bc60) Mar 18 07:02:26 kletskop kernel: Element != First TD Mar 18 07:02:26 kletskop kernel: 0: [d0e2a000] link (10e2a030) e3 Length=3f MaxLen=3f DT0 EndPt=2 Dev=2, PID=69(IN) (buf=191b0000) Mar 18 07:02:26 kletskop kernel: 1: [d0e2a030] link (10e2a060) e3 Length=3f MaxLen=3f DT1 EndPt=2 Dev=2, PID=69(IN) (buf=191b0040) Mar 18 07:02:26 kletskop kernel: 2: [d0e2a060] link (10e2a090) e3 Length=3f MaxLen=3f DT0 EndPt=2 Dev=2, PID=69(IN) (buf=191b0080) Mar 18 07:02:26 kletskop kernel: 3: [d0e2a090] link (10e2a0c0) e3 Length=3f MaxLen=3f DT1 EndPt=2 ...etc (see http://www.oink-oink-oink.net/usb-problem/syslog2.gz for the full listing)... Mar 18 07:02:26 kletskop kernel: 148: [d0e2bbd0] link (10e2bc00) e3 Length=3f MaxLen=3f DT0 EndPt=2 Dev=2, PID=69(IN) (buf=191b2500) Mar 18 07:02:26 kletskop kernel: 149: [d0e2bc00] link (10e2bc30) e3 Length=3f MaxLen=3f DT1 EndPt=2 Dev=2, PID=69(IN) (buf=191b2540) Mar 18 07:02:26 kletskop kernel: 150: [d0e2bc30] link (10e2bc60) e3 Length=3f MaxLen=3f DT0 EndPt=2 Dev=2, PID=69(IN) (buf=191b2580) Mar 18 07:02:26 kletskop kernel: 151: [d0e2bc60] link (00000001) e3 IOC Stalled Babble Length=f MaxLen=f DT1 EndPt=2 Dev=2, PID=69(IN) (buf=191b25c0) Mar 18 07:02:26 kletskop kernel: Mar 18 07:02:26 kletskop kernel: scanner.c: read stats(0): result:-75 this_read:9680 partial:9680 count:9680 Mar 18 07:02:26 kletskop kernel: scanner.c: read_scanner(0): funky result:-75. Consult Documentation/usb/scanner.txt. Mar 18 07:02:36 kletskop kernel: usb_control/bulk_msg: timeout Mar 18 07:02:36 kletskop kernel: scanner.c: read stats(0): result:-110 this_read:8 partial:0 count:8 Mar 18 07:02:56 kletskop kernel: usb_control/bulk_msg: timeout Mar 18 07:02:56 kletskop kernel: scanner.c: read stats(0): result:-110 this_read:8 partial:0 count:8 ------------------------------------------------------- This SF.net email is sponsored by: Does your code think in ink? You could win a Tablet PC. Get a free Tablet PC hat just for playing. What are you waiting for? http://ads.sourceforge.net/cgi-bin/redirect.pl?micr5043en _______________________________________________ [EMAIL PROTECTED] To unsubscribe, use the last form field at: https://lists.sourceforge.net/lists/listinfo/linux-usb-users
