On Mon, 28 Dec 2020 20:55:33 +0000 [email protected] wrote: > >Synopsis: After first successful scan on Canon MG3250 > >scanner, all next ugenread()s timeout Category: kernel > >Environment: > System : OpenBSD 6.8 > Details : OpenBSD 6.8-current (GENERIC.MP) #246: Sun Dec > 27 18:17:02 MST 2020 > [email protected]:/usr/src/sys/arch/amd64/compile/GENERIC.MP > > Architecture: OpenBSD.amd64 > Machine : amd64 > >Description: > When I use scanner first time via scanimage: > > scanimage --device-name pixma:04A91762_860FE4 \ > --format png --mode gray \ > --resolution 300 --output-file scan.png > > above command works and PNG file is properly saved with scanned > image. When I want to scan again command fails: > > scanimage: sane_read: Operation was canceled > > When increasing libusb debug logs example iteration of failed attempt > to scan looks as follows: > > [ 0.584877] [0003ef68] libusb: debug [libusb_alloc_transfer] transfer > 0xea40237d150 [ 0.584902] [0003ef68] libusb: debug > [libusb_submit_transfer] transfer 0xea40237d150 [ 0.584921] > [0003ef68] libusb: debug [obsd_submit_transfer] [ 0.584979] > [0003ef68] libusb: debug [_access_endpoint] endpoint 8 mode 0 [ > 1.579537] [0003ef68] libusb: debug [_errno_to_libusb] error: > Operation timed out (60) [ 1.579601] [0003ef68] libusb: debug > [libusb_free_transfer] transfer 0xea40237d150 [ 1.579696] [0003ef68] > libusb: debug [libusb_clear_halt] endpoint 88 [ 1.579862] [0003ef68] > libusb: debug [obsd_clear_halt] > > On the kernel side my debug printfs look as follow: > > 2020-12-27T12:29:39.939Z pce-0067 /bsd: MMM>> dv_xname=ugen0 endpt=8 > flag=0 [ugenread()|ugen.c|644] 2020-12-27T12:29:39.940Z pce-0067 > /bsd: MMM dv_xname=ugen0 endpt=8 [ugen_do_read()|ugen.c|484] > 2020-12-27T12:29:39.940Z pce-0067 /bsd: MMM dv_xname=ugen0 endpt=8 > xfertype=2 [ugen_do_read()|ugen.c|503] 2020-12-27T12:29:39.940Z > pce-0067 /bsd: MMM start UE_BULK [ugen_do_read()|ugen.c|549] > 2020-12-27T12:29:42.997Z pce-0067 /bsd: MMM ! polling=0 flags=16 > err=0 xfer->flags=6 xfer->status=15 xfer->done=1 > [usbd_transfer()|usbdi.c|375] 2020-12-27T12:29:42.998Z pce-0067 /bsd: > MMM final polling=0 xfer->flags=6 xfer->status=15 > [usbd_transfer()|usbdi.c|389] 2020-12-27T12:29:42.998Z pce-0067 /bsd: > MMM dv_xname=ugen0 endpt=8 err=15 n=1024 timeout=3000 flags=6 > [ugen_do_read()|ugen.c|565] 2020-12-27T12:29:42.998Z pce-0067 /bsd: > MMM end UE_BULK [ugen_do_read()|ugen.c|582] 2020-12-27T12:29:42.998Z > pce-0067 /bsd: MMM<< dv_xname=ugen0 endpt=8 error=60 > [ugenread()|ugen.c|647] > > It maybe hard to see from above but the core of it is that in usbdi.c > file, in function usbd_transfer(): > > 358 } else { > 359 while (!xfer->done) { > 360 flags = PRIBIO|(xfer->flags & > USBD_CATCH ? PCATCH : 0); 361 > 362 err = tsleep_nsec(xfer, flags, > "usbsyn", INFSLP); 363 if (err && > !xfer->done) { 364 > usbd_abort_pipe(pipe); 365 if (err > == EINTR) 366 xfer->status > = USBD_INTERRUPTED; 367 else > 368 xfer->status = > USBD_TIMEOUT; 369 } > 370 } > 371 } > > above function tsleep_nsec() on line 362 times out and xfer->status > is set to USBD_TIMEOUT on line 368. When tsleep_nsec() times out, > xhci_timeout() and xhci_timeout_task() from xhci.c are executed. > > I've started adding printfs to xhci_device_generic_transfer() but that > slowed code path to the point that problem disappeared and scanner > started to work reliably, but (obviously) scan got really slow, from > couple of seconds to about 4 minutes. > > This is where I got stuck as I got out of ideas how to drill this down > further in efficient manner. Decided to look on the mailing list and > found: > > - https://marc.info/?t=158150362100001&r=1&w=2 > - https://marc.info/?t=158729021900001&r=1&w=2 > > In above email threads I found patch quoted below in the Fix section. > > >How-To-Repeat: > - boot OpenBSD > - power on scanner > - use scanimage to scan a picture > - when first scan succeeds > - any another scan fails with tsleep_nsec() on line 362 from > usbdi.c function usbd_transfer() is timing out > - unplugging from USB scanner is needed to be able to scan > again > - or power cycle scanner > - or power cycle OpenBSD > - basically ugen(4) detach / attach is needed > > >Fix: > Per email threads on tech@ from above marc.info links below is > not proper solution, but a workaround: > > --8<-- > Index: dev/usb/ugen.c > =================================================================== > RCS file: /cvs/src/sys/dev/usb/ugen.c,v > retrieving revision 1.109 > diff -u -p -u -r1.109 ugen.c > --- dev/usb/ugen.c 25 Dec 2020 12:59:52 -0000 1.109 > +++ dev/usb/ugen.c 27 Dec 2020 22:38:59 -0000 > @@ -441,6 +442,7 @@ ugen_do_close(struct ugen_softc *sc, int > DPRINTFN(5, ("ugenclose: endpt=%d dir=%d sce=%p\n", > endpt, dir, sce)); > > + usbd_clear_endpoint_stall(sce->pipeh); > /* MMM */ usbd_close_pipe(sce->pipeh); > sce->pipeh = NULL; > > -->8-- > > It makes my scanner work reliably. There is still a second problem > metioned by me in https://marc.info/?t=160672895400002&r=1&w=2 but > that's different issue. > > However my question would be, any idea how to proceed from where I am > at the moment? Any clues? > > I've also CC'ed Natasha as she may be interested in this thread, as > she was the one who started email threads from above marc.info URLs.
I'll try to reproduce this issue here, but at the moment scanimage doesn't like my EPSON ET-2750 too much ...
