On Wed, Aug 26, 2020 at 11:27:21PM +0200, Marcus Glocker wrote:
> On Wed, 26 Aug 2020 19:20:26 +0000
> Mikolaj Kucharski <[email protected]> wrote:
>
> > On Wed, Aug 26, 2020 at 06:54:59PM +0000, Mikolaj Kucharski wrote:
> > > On Wed, Aug 26, 2020 at 06:45:28PM +0000, Mikolaj Kucharski wrote:
> > ...
> > > >
> > > > Do you have any theory why first control request is returning
> > > > wTotalLength=32 and second is returning wTotalLength=55? It also
> > > > seem that bNumInterface has different value between the runs.
> > >
> > > I ran more `scanimage -L` commands in a row and wTotalLength=32
> > > doesn't occur any more. As I'm remote to the machine and the
> > > printer I don't see it, but I imagine that printer/scanner goes to
> > > sleep after certain amount of time of inactivity.
> > >
> > > Maybe it's related that first call wakes up the printer/scanner and
> > > then wTotalLength=32. After that when printer/scanner is up all
> > > wTotalLength=55. I can test it again during a day tomorrow with
> > > hours of break in between of `scanimage -L` runs to see am I seeing
> > > more of this behaviour.
> > >
> >
> > Ok, so I waited 15+ minutes between scanimage -L, as I suspect that
> > would be enough time to get printer to sleep and yeah, I see again
> > wTotalLength=32:
>
> OK, this makes sense.
>
> Does this diff fix the issue?
> I'm hoping that we don't require a delay between the requests.
Yes, this diff does fix the issue. It works really well. I can confirm
this is related to the printer going to sleep-mode as that printer has
also web UI and there I can see status of the printer, for example page
says:
Sleeping...
or, when `scanimage -L` wakes up the printer it says:
Ready to Copy
Eco Mode 01
and this relates to wTotalLength 32 vs 55. After below diff all works
without panic and `scanimage -L` works reliably and scanning itself also
works.
I've also tested your diff against (kernel has disable ulpt applied):
# dmesg
...
ugen0 at uhub0 port 4 "Canon MG3200 series" rev 2.00/1.04 addr 2
# usbdevs -v
Controller /dev/usb0:
addr 01: 1022:0000 AMD, xHCI root hub
super speed, self powered, config 1, rev 1.00
driver: uhub0
addr 02: 04a9:1762 Canon, MG3200 series
high speed, self powered, config 1, rev 1.04, iSerial 860FE4
driver: ugen0
Controller /dev/usb1:
addr 01: 1022:0000 AMD, EHCI root hub
high speed, self powered, config 1, rev 1.00
driver: uhub1
addr 02: 0438:7900 Advanced Micro Devices, Hub
high speed, self powered, config 1, rev 0.18
driver: uhub2
# scanimage -L
device `pixma:04A91762_860FE4' is a CANON Canon PIXMA MG3200 Series
multi-function peripheral
That Canon MG3250 printer/scanner didn't had this issue, but I just
wanted to check is your diff also working on a device, which was working
before the change. All good here.
Thank you very much Marcus for fixing the problem!
> > # grep -F '/bsd' /var/log/messages | cut -b35- | head -n30
> > /bsd: USB_DEVICE_GET_FDESC wTotalLength free = 25
> > /bsd: USB_DEVICE_GET_FDESC wTotalLength free = 55
> > /bsd: USB_DEVICE_GET_FDESC wTotalLength free = 25
> > /bsd: USB_DEVICE_GET_FDESC wTotalLength free = 25
> > /bsd: USB_DEVICE_GET_FDESC wTotalLength free = 216
> > /bsd: 1:
> > /bsd: bLength=9
> > /bsd: bDescriptorType=2
> > /bsd: wTotalLength=32
> > /bsd: bNumInterface=1
> > /bsd: bConfigurationValue=1
> > /bsd: iConfiguration=0
> > /bsd: bmAttributes=0xc0
> > /bsd: bMaxPower=1
> > /bsd: 2:
> > /bsd: bLength=9
> > /bsd: bDescriptorType=2
> > /bsd: wTotalLength=55
> > /bsd: bNumInterface=2
> > /bsd: bConfigurationValue=1
> > /bsd: iConfiguration=0
> > /bsd: bmAttributes=0xc0
> > /bsd: bMaxPower=1
> > /bsd: USB_DEVICE_GET_FDESC wTotalLength free = 55
> > /bsd: USB_DEVICE_GET_FDESC wTotalLength free = 55
> > /bsd: USB_DEVICE_GET_FDESC wTotalLength free = 25
> > /bsd: USB_DEVICE_GET_FDESC wTotalLength free = 25
> > /bsd: USB_DEVICE_GET_FDESC wTotalLength free = 216
> > /bsd: USB_DEVICE_GET_FDESC wTotalLength free = 216
> > /bsd: USB_DEVICE_GET_FDESC wTotalLength free = 55
>
>
> Index: sys/dev/usb/usb_subr.c
> ===================================================================
> RCS file: /cvs/src/sys/dev/usb/usb_subr.c,v
> retrieving revision 1.151
> diff -u -p -u -p -r1.151 usb_subr.c
> --- sys/dev/usb/usb_subr.c 31 Jul 2020 10:49:33 -0000 1.151
> +++ sys/dev/usb/usb_subr.c 26 Aug 2020 21:25:31 -0000
> @@ -1366,6 +1366,7 @@ usbd_get_cdesc(struct usbd_device *dev,
> usb_config_descriptor_t *cdesc, *tdesc, cdescr;
> u_int len;
> usbd_status err;
> + int i;
>
> if (index == USB_CURRENT_CONFIG_INDEX) {
> tdesc = usbd_get_config_descriptor(dev);
> @@ -1378,11 +1379,23 @@ usbd_get_cdesc(struct usbd_device *dev,
> memcpy(cdesc, tdesc, len);
> DPRINTFN(5,("%s: current, len=%u\n", __func__, len));
> } else {
> - err = usbd_get_desc(dev, UDESC_CONFIG, index,
> - USB_CONFIG_DESCRIPTOR_SIZE, &cdescr);
> - if (err || cdescr.bDescriptorType != UDESC_CONFIG)
> - return (0);
> - len = UGETW(cdescr.wTotalLength);
> + /*
> + * Some devices return false configuration descriptor values
> + * on the first request, e.g. when they are in sleep mode.
> + * Therefore compare multiple request results; Two for sane
> + * values, three for initial false values.
> + */
> + for (len = 0, i = 0; i < 3; i++) {
> + err = usbd_get_desc(dev, UDESC_CONFIG, index,
> + USB_CONFIG_DESCRIPTOR_SIZE, &cdescr);
> + if (err || cdescr.bDescriptorType != UDESC_CONFIG)
> + return (0);
> + if (len == UGETW(cdescr.wTotalLength))
> + break;
> + len = UGETW(cdescr.wTotalLength);
> + }
> + if (i == 3)
> + return (NULL);
> DPRINTFN(5,("%s: index=%d, len=%u\n", __func__, index, len));
> if (lenp)
> *lenp = len;
--
Regards,
Mikolaj
