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.
On Mon, Jan 04, 2021 at 09:13:12AM +0100, Marcus Glocker wrote:
>
> I've tested the following diff on a xhci(4), and a ehci(4) HC with the
> Canon LiDE 400 scanner.
>
>
> Index: dev/usb/ugen.c
> ===================================================================
> RCS file: /cvs/src/sys/dev/usb/ugen.c,v
> retrieving revision 1.109
> diff -u -p -u -p -r1.109 ugen.c
> --- dev/usb/ugen.c 25 Dec 2020 12:59:52 -0000 1.109
> +++ dev/usb/ugen.c 4 Jan 2021 07:08:14 -0000
> @@ -46,9 +46,12 @@
> #include <sys/vnode.h>
> #include <sys/poll.h>
>
> +#include <machine/bus.h>
> +
> #include <dev/usb/usb.h>
> #include <dev/usb/usbdi.h>
> #include <dev/usb/usbdi_util.h>
> +#include <dev/usb/usbdivar.h>
>
> #ifdef UGEN_DEBUG
> #define DPRINTF(x) do { if (ugendebug) printf x; } while (0)
> @@ -114,6 +117,7 @@ int ugen_do_close(struct ugen_softc *, i
> int ugen_set_config(struct ugen_softc *sc, int configno);
> int ugen_set_interface(struct ugen_softc *, int, int);
> int ugen_get_alt_index(struct ugen_softc *sc, int ifaceidx);
> +int ugen_endpoint_halt(struct ugen_softc *, struct usbd_interface *);
>
> #define UGENUNIT(n) ((minor(n) >> 4) & 0xf)
> #define UGENENDPOINT(n) (minor(n) & 0xf)
> @@ -302,6 +306,15 @@ ugenopen(dev_t dev, int flag, int mode,
> DPRINTFN(5, ("ugenopen: sc=%p, endpt=%d, dir=%d, sce=%p\n",
> sc, endpt, dir, sce));
> edesc = sce->edesc;
> + /*
> + * XHCI resets the data toggle state, used for interrupt and
> + * bulk transfers, on a pipe open/close (add/drop) cycle.
> + * Therefore we also need to reset the device endpoints data
> + * toggles for the current interface to make sure we stay in
> + * sync.
> + */
> + if (sc->sc_udev->bus->usbrev == USBREV_3_0)
> + ugen_endpoint_halt(sc, sce->iface);
> switch (UE_GET_XFERTYPE(edesc->bmAttributes)) {
> case UE_INTERRUPT:
> if (dir == OUT) {
> @@ -940,6 +953,50 @@ ugen_get_alt_index(struct ugen_softc *sc
> if (err)
> return (-1);
> return (usbd_get_interface_altindex(iface));
> +}
> +
> +int
> +ugen_endpoint_halt(struct ugen_softc *sc, struct usbd_interface *iface)
> +{
> + usb_interface_descriptor_t *id;
> + usb_endpoint_descriptor_t *ed;
> + usbd_status err;
> + int i;
> +
> + /* Only halt interface endpoints when none are in use. */
> + for (i = 0; i < USB_MAX_ENDPOINTS; i++) {
> + if (i == USB_CONTROL_ENDPOINT)
> + continue;
> + if (sc->sc_is_open[i] != 0)
> + return (0);
> + }
> + DPRINTFN(1,("%s: halt interface endpoints\n", __func__));
> +
> + id = usbd_get_interface_descriptor(iface);
> + if (id == NULL)
> + return (-1);
> +
> + for (i = 0; i < id->bNumEndpoints; i++) {
> + ed = usbd_interface2endpoint_descriptor(iface, i);
> + if (ed == NULL)
> + return (-1);
> +
> + switch (UE_GET_XFERTYPE(ed->bmAttributes)) {
> + case UE_BULK:
> + case UE_INTERRUPT:
> + err = usbd_clear_endpoint_feature(sc->sc_udev,
> + ed->bEndpointAddress, UF_ENDPOINT_HALT);
> + if (err) {
> + printf("%s: halt endpoint failed!\n", __func__);
> + return (-1);
> + }
> + break;
> + default:
> + break;
> + }
> + }
> +
> + return (0);
> }
>
> int
> Index: dev/usb/usbdi_util.c
> ===================================================================
> RCS file: /cvs/src/sys/dev/usb/usbdi_util.c,v
> retrieving revision 1.44
> diff -u -p -u -p -r1.44 usbdi_util.c
> --- dev/usb/usbdi_util.c 6 Oct 2019 17:11:51 -0000 1.44
> +++ dev/usb/usbdi_util.c 4 Jan 2021 07:08:14 -0000
> @@ -192,6 +192,19 @@ usbd_clear_port_feature(struct usbd_devi
> }
>
> usbd_status
> +usbd_clear_endpoint_feature(struct usbd_device *dev, int epaddr, int sel)
> +{
> + usb_device_request_t req;
> +
> + req.bmRequestType = UT_WRITE_ENDPOINT;
> + req.bRequest = UR_CLEAR_FEATURE;
> + USETW(req.wValue, sel);
> + USETW(req.wIndex, epaddr);
> + USETW(req.wLength, 0);
> + return (usbd_do_request(dev, &req, 0));
> +}
> +
> +usbd_status
> usbd_set_port_feature(struct usbd_device *dev, int port, int sel)
> {
> usb_device_request_t req;
> Index: dev/usb/usbdi_util.h
> ===================================================================
> RCS file: /cvs/src/sys/dev/usb/usbdi_util.h,v
> retrieving revision 1.29
> diff -u -p -u -p -r1.29 usbdi_util.h
> --- dev/usb/usbdi_util.h 8 Dec 2014 22:00:11 -0000 1.29
> +++ dev/usb/usbdi_util.h 4 Jan 2021 07:08:14 -0000
> @@ -41,6 +41,7 @@ usbd_status usbd_set_hub_feature(struct
> usbd_status usbd_clear_hub_feature(struct usbd_device *, int);
> usbd_status usbd_set_port_feature(struct usbd_device *dev, int, int);
> usbd_status usbd_clear_port_feature(struct usbd_device *, int, int);
> +usbd_status usbd_clear_endpoint_feature(struct usbd_device *, int, int);
> usbd_status usbd_get_device_status(struct usbd_device *, usb_status_t *);
> usbd_status usbd_get_hub_status(struct usbd_device *, usb_hub_status_t *);
> usbd_status usbd_get_hub_descriptor(struct usbd_device *,
>
--
Regards,
Mikolaj
