[sane-devel] Fi-4120C2 - USB bulk transfers failing with -ETIMEDOUT or -EPIPE

Wed Feb 15 22:21:52 UTC 2006

strace is not very helpful, a debug log from sane would work better.

SANE_DEBUG_FUJITSU=255 scanimage 2>4120c2.log > /dev/null

then look thru the log for the errors. likely will appear as blank lines.

send me the section of the log right around the first error.

i will try to work on it this evening, along with all the other bug 
reports.

allan

On Wed, 15 Feb 2006, Charles Duffy wrote:

> I'm able to query the scanner's existance, but attempting to actually run a 
> scan, (1) the scanner never actually pulls paper through the feed, and (2) 
> all but the initial bulk requests return errors. After this has occurred, the 
> scanner is nonresponsive (and doesn't show up in "scanimage -L" output, if 
> scanimage returns at all rather than hanging) until the scanner is restarted.
>
> Running scanimage with --test or --dont-scan, by contrast, is uneventful 
> (prior to an unsuccessful run).
>
> I've read that folks are using this scanner succesfully (which is extremely 
> encouraging), but note that I had to add its vendor and device IDs (0x04c5 
> and 0x10ae) to /usr/local/etc/sane.d/fujitsu.conf for it to be recognized. 
> I'm running sane-backends 1.0.17. The system in question is running Linux 
> 2.6.5 (more particularly, the kernel is Novell/SuSE's 2.6.5-7.97-default from 
> their SLES9 distribution). The USB controller is an onboard SiS unit using 
> the OHCI driver. The install libusb version is 0.1.8.
>
> If 'yall suspect that this is a hardware issue, I'd be glad to test against a 
> different machine.
>
>
> Quoting from the system log:
>
> 14:55:27 kernel: usb 2-1: new full speed USB device using address 7
> 14:55:27 /etc/hotplug/usb.agent[10305]: need a device for this command
> 14:55:46 scanimage: resmgr: server response code 502
> 14:55:46 last message repeated 8 times
> 14:55:46 scanimage: resmgr: server response code 200
> 14:55:46 scanimage: resmgr: server response code 200
> 14:56:17 kernel: usb 2-1: bulk timeout on ep1in
> 14:56:17 kernel: usbfs: USBDEVFS_BULK failed dev 7 ep 0x81 len 13 ret -110
> 14:56:22 kernel: usb 2-1: control timeout on ep0out
> 14:56:22 kernel: usbfs: USBDEVFS_BULK failed dev 7 ep 0x81 len 13 ret -32
> 14:56:27 kernel: usb 2-1: control timeout on ep0out
> 14:56:27 kernel: usbfs: USBDEVFS_BULK failed dev 7 ep 0x2 len 31 ret -32
> 14:56:32 kernel: usb 2-1: control timeout on ep0out
> 14:56:32 kernel: usbfs: USBDEVFS_BULK failed dev 7 ep 0x2 len 31 ret -32
> 14:57:02 last message repeated 5069 times
> 14:57:37 last message repeated 5505 times
>
> Quoting from an strace of scanimage:
>
> 14:55:46.997361 open("/proc/bus/usb/002/007", O_RDWR) = 3
> 14:55:46.997516 ioctl(3, USBDEVFS_SETCONFIGURATION, 0xbfffd0b4) = 0
> 14:55:46.999222 ioctl(3, USBDEVFS_CLAIMINTERFACE, 0xbfffd0b4) = 0
> 14:55:46.999391 ioctl(3, USBDEVFS_BULK, 0xbfffcc20) = 31
> 14:55:47.002205 ioctl(3, USBDEVFS_BULK, 0xbfffcc20) = 13
> 14:55:47.003263 ioctl(3, USBDEVFS_BULK, 0xbfffcc50) = 31
> 14:55:47.006203 ioctl(3, USBDEVFS_BULK, 0xbfffcc50) = 13
> 14:55:47.007352 ioctl(3, USBDEVFS_BULK, 0xbfffcc50) = 31
> 14:55:47.010224 ioctl(3, USBDEVFS_BULK, 0xbfffcc50) = 12
> 14:55:47.013197 ioctl(3, USBDEVFS_BULK, 0xbfffcc50) = 13
> 14:55:47.014281 ioctl(3, USBDEVFS_BULK, 0xbfffcc50) = 31
> 14:55:47.017213 ioctl(3, USBDEVFS_BULK, 0xbfffcc50) = 8
> 14:55:47.020192 ioctl(3, USBDEVFS_BULK, 0xbfffcc50) = -1 ETIMEDOUT 
> (Connection timed out)
> 14:56:17.015395 ioctl(3, USBDEVFS_CLEAR_HALT, 0xbfffcc84) = -1 ETIMEDOUT 
> (Connection timed out)
> 14:56:22.015089 ioctl(3, USBDEVFS_BULK, 0xbfffcc50) = 31
> 14:56:22.016821 ioctl(3, USBDEVFS_BULK, 0xbfffcc50) = -1 EPIPE (Broken pipe)
> 14:56:22.018964 ioctl(3, USBDEVFS_CLEAR_HALT, 0xbfffcc84) = -1 
ETIMEDOUT 
> (Connection timed out)
> 14:56:27.018948 ioctl(3, USBDEVFS_BULK, 0xbfffcc20) = -1 EPIPE (Broken pipe)
> 14:56:27.021793 ioctl(3, USBDEVFS_CLEAR_HALT, 0xbfffcc54) = -1 ETIMEDOUT 
> (Connection timed out)
> 14:56:32.021829 ioctl(3, USBDEVFS_BULK, 0xbfffcc20) = -1 EPIPE (Broken pipe)
> 14:56:32.023112 ioctl(3, USBDEVFS_CLEAR_HALT, 0xbfffcc54) = 0
>
> Further, when I try pressing ctrl+c to cancel the operation, it then starts 
> sending usbdevfs-related ioctls to fd0:
>
> 4:57:37.506541 --- SIGINT (Interrupt) @ 0 (0) ---
> 14:57:37.506702 write(2, "scanimage: received signal 2\n", 29) = 29
> 14:57:37.508154 write(2, "scanimage: trying to stop scanne"..., 34) = 34
> 14:57:37.509602 ioctl(3, USBDEVFS_BULK, 0xbfffc39c) = -1 EPIPE (Broken pipe)
> 14:57:37.510819 ioctl(3, USBDEVFS_CLEAR_HALT, 0xbfffc3d0) = 0
> 14:57:37.512709 ioctl(3, USBDEVFS_RELEASEINTERFACE, 0xbfffc870) = 0
> 14:57:37.515687 close(3)                = 0
> 14:57:37.515766 sigreturn()             = ? (mask now [])
> 14:57:37.515918 ioctl(0, USBDEVFS_CLEAR_HALT, 0xbfffcc54) = -1 EINVAL 
> (Invalid argument)
> 14:57:37.516100 ioctl(0, USBDEVFS_BULK, 0xbfffcc20) = -1 EINVAL (Invalid 
> argument)
>
> ...and ceases only when terminated.
>
>
>

-- 
"so don't tell us it can't be done, putting down what you don't know.
money isn't our god, integrity will free our souls" - Max Cavalera