Hey Mikolaj,

On Thu, Aug 27, 2020 at 06:49:12PM +0000, Mikolaj Kucharski wrote:

> 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.

All right.
 
> 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!

Cool - Thanks for the thoroughly testing.

As discussed with Theo before, we'll first fix the underlying issue of
the malloc(size)/free(,size) which is fundamentally handled wrong in this
case.

I'll afterwards seek for another OK to get the diff in you've tested.
 
> > > # 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

Reply via email to