On Sat, 9 Jan 2021 19:14:07 +0000 Mikolaj Kucharski <miko...@kucharski.name> wrote:
> Marcus, > > I'm just catching up here. I know you posted newer diff, but I would > like to comment what I've seen with your below diff. > > I'm running sane-backends with my SANE_CUSTOM_LIBUSB_TIMEOUT diff, as > shown in one of my eariler emails in this thread at: > > https://marc.info/?l=openbsd-bugs&m=160934505403471&w=2 > > Your below diff improves consistency of ugen(4) and my scanner. Every > attempt to scan is the same and fails with: > > scanimage: sane_read: Error during device I/O > > [ 1.864924] [0002a2bc] libusb: debug [libusb_get_next_timeout] first > timeout already expired [ 1.865168] [0002a2bc] libusb: debug > [libusb_cancel_transfer] transfer 0x8342592158 [ 1.865191] [0002a2bc] > libusb: debug [obsd_cancel_transfer] [ 1.865204] [0002a2bc] libusb: > error [libusb_cancel_transfer] cancel transfer failed error -12 [ > 1.865217] [0002a2bc] libusb: warning [handle_timeout] async cancel > failed -12 [ 1.865249] [0002a2bc] libusb: debug > [libusb_get_next_timeout] no URB with timeout or all handled by OS; > no timeout! [ 1.865264] [0002a2bc] libusb: debug > [libusb_handle_events_timeout_completed] doing our own event handling > [ 1.865278] [0002a2bc] libusb: debug [usbi_wait_for_events] poll() 1 > fds with timeout in 60000ms [ 1.865299] [0002a2bc] libusb: debug > [usbi_wait_for_events] poll() returned 1 [ 1.865311] [0002a2bc] > libusb: debug [handle_event_trigger] event triggered [ 1.865325] > [0002a2bc] libusb: debug [usbi_handle_transfer_completion] transfer > 0x8342592158 has callback 0x838c433d00 [ 1.865339] [0002a2bc] libusb: > debug [sync_transfer_cb] actual_length=0 [ 1.865363] [0002a2bc] > libusb: debug [libusb_free_transfer] transfer 0x8342592158 > [18:57:34.575862] [sanei_usb] sanei_usb_read_int() ret=0 > trans_bytes=0 [sanei_usb.c:4357] [18:57:34.575900] [sanei_usb] > sanei_usb_read_int: read returned EOF [18:57:34.575926] [pixma] > sanei_pixma_wait_interrupt() ELSE error=-14 [pixma_io_sanei.c:544] > [18:57:34.575956] [pixma] INTR T=1.865 len=-14 [18:57:34.575979] > [pixma] ERROR: EEOF > > Basically we can see as timeout would be to short. I can run scanimage > multile times and it always fails the same. This is an improvement > from cvs HEAD as first run usually would fail with above error (with > default timeouts) and any other run would fail with: > > scanimage: sane_read: Operation was canceled > > as reported initially (tsleep_nsec() timing out in usbd_transfer()). > So this is an improvement -- the consisteny of behaviour. > > Above libusb debug output is mentioning 60000ms timeout, but I didn't > look at the code where this value comes from, but this is not the > default timeout from sane-backends. Different callouts from pixma > driver to libusb have different timeout values by default. > > Anyway, with default it doesn't work as you can see above, so I tried > various values of SANE_CUSTOM_LIBUSB_TIMEOUT to see will increasing > the time out help and it does. > > 3000 ms, it's to short and scanimage still fails with read returned > EOF. > > 5000 ms, scanning heads start scanning, but half way through the flat > bed it seems timeout is triggered and scanning head stops and goes > back to dedault position and scanimage fails. > > 6000 ms, scanning head is able to reach end of the flatbed and > scanimage succeeds. > > 10000 ms, same as 6 seconds above. I can repeat this operation > multiple times and it works. Same for above. > > 15000 ms, or above, scanimage fails with timeouts and is not able to > scan an image. > > I'm going to test now your next diff. Hello Mikolaj, I think you're mixing up two different issues now. The first issue is with our ugen(4) implementation, where the DATA toggle gets out of sync with xhci(4), and therefore after the first successful data exchange, all following will fail, until you detach/attach the device which will reset the DATA toggle again. The second issue seems to be a bug in the sane-backends software. I had a problem related to that with my PIXMA scanner as well. It could be the same issue you're seeing. I've opened an issue upstream for that: https://gitlab.com/sane-project/backends/-/issues/412 In the meantime I've also provided a patch upstream for the issue. They are currently checking whether it's the right fix to do. Can you try this patch with our sane-backends port as well, and see whether if fixes your issue? Index: graphics/sane-backends/Makefile =================================================================== RCS file: /cvs/ports/graphics/sane-backends/Makefile,v retrieving revision 1.95 diff -u -p -u -p -r1.95 Makefile --- graphics/sane-backends/Makefile 20 Dec 2020 09:56:36 -0000 1.95 +++ graphics/sane-backends/Makefile 9 Jan 2021 22:07:38 -0000 @@ -5,7 +5,7 @@ BROKEN-alpha= ICE hp5590.c:1141: error: COMMENT= API for accessing scanners, backends DISTNAME= sane-backends-1.0.31 -REVISION= 1 +REVISION= 2 SHARED_LIBS += sane 2.1 # unknown Index: graphics/sane-backends/patches/patch-backend_pixma_pixma_io_sanei_c =================================================================== RCS file: graphics/sane-backends/patches/patch-backend_pixma_pixma_io_sanei_c diff -N graphics/sane-backends/patches/patch-backend_pixma_pixma_io_sanei_c --- /dev/null 1 Jan 1970 00:00:00 -0000 +++ graphics/sane-backends/patches/patch-backend_pixma_pixma_io_sanei_c 9 Jan 2021 22:07:38 -0000 @@ -0,0 +1,15 @@ +$OpenBSD$ + +Index: backend/pixma/pixma_io_sanei.c +--- backend/pixma/pixma_io_sanei.c.orig Sun Aug 23 13:59:20 2020 ++++ backend/pixma/pixma_io_sanei.c Tue Jan 5 15:30:06 2021 +@@ -538,8 +538,7 @@ pixma_wait_interrupt (pixma_io_t * io, void *buf, unsi + #endif + error = map_error (sanei_usb_read_int (io->dev, buf, &count)); + } +- if (error == PIXMA_EIO || +- (io->interface == INT_BJNP && error == PIXMA_EOF)) /* EOF is a bjnp timeout error! */ ++ if (error == PIXMA_EIO || error == PIXMA_EOF) + error = PIXMA_ETIMEDOUT; /* FIXME: SANE doesn't have ETIMEDOUT!! */ + if (error == 0) + error = count;
