Re: u-boot debug, was: Re: U-boot on RPI3, sees disk but won't boot it

On 2022-Sep-28, at 20:04, Mark Millard <marklmi@yahoo.com> wrote:

> On 2022-Sep-28, at 18:03, Mark Millard <marklmi@yahoo.com> wrote:
> 
>> On 2022-Sep-28, at 17:21, bob prohaska <fbsd@www.zefox.net> wrote:
>> 
>>> With the correct patches finally in place there is some
>>> extra output from u-boot:
>>> 
>>> U-Boot 2022.04 (Sep 28 2022 - 16:45:12 -0700)
>>> . . .
>>> starting USB...
>>> . . .
>>> usb_new_device: Cannot read configuration, skipping device 152d:0583
>> 
>> The above is reporting U-Boot having a problem dealing with
>> your bridge/drive combination as seen via bridge access,
>> presuming that I recognize the 152d:0583 correctly.
>> 
>> 
>> 
>> Interestingly, that message is not from the routine usb_new_device
>> but is from:
>> 
>> 
>> int usb_select_config(struct usb_device *dev)
>> {
>> . . .
>>       /*
>>        * Kingston DT Ultimate 32GB USB 3.0 seems to be extremely sensitive
>>        * about this first Get Descriptor request. If there are any other
>>        * requests in the first microframe, the stick crashes. Wait about
>>        * one microframe duration here (1mS for USB 1.x , 125uS for USB 2.0).
>>        */
>>       mdelay(1);
>> 
>>       /* only support for one config for now */
>>       err = usb_get_configuration_len(dev, 0);
>>       if (err >= 0) {
>>               tmpbuf = (unsigned char *)malloc_cache_aligned(err);
>>               if (!tmpbuf)
>>                       err = -ENOMEM;
>>               else
>>                       err = usb_get_configuration_no(dev, 0, tmpbuf, err);
>>       }
>>       if (err < 0) {
>>               printf("usb_new_device: Cannot read configuration, " \
>>                      "skipping device %04x:%04x\n",
>>                      dev->descriptor.idVendor, dev->descriptor.idProduct);
>>               free(tmpbuf);
>>               return err;
>>       }
>> . . .
>> 
>> where:
>> 
>> /**********************************************************************
>> * gets len of configuration cfgno
>> */
>> int usb_get_configuration_len(struct usb_device *dev, int cfgno)
>> {
>>       int result;
>>       ALLOC_CACHE_ALIGN_BUFFER(unsigned char, buffer, 9);
>>       struct usb_config_descriptor *config;
>> 
>>       config = (struct usb_config_descriptor *)&buffer[0];
>>       result = usb_get_descriptor(dev, USB_DT_CONFIG, cfgno, buffer, 9);
>>       if (result < 9) {   
>>               if (result < 0)
>>                       printf("unable to get descriptor, error %lX\n",
>>                               dev->status);
>>               else
>>                       printf("config descriptor too short " \
>>                               "(expected %i, got %i)\n", 9, result);
>>               return -EIO;
>>       }
>>       return le16_to_cpu(config->wTotalLength);
>> }
>> 
>> and:
>> 
>> /**********************************************************************
>> * gets configuration cfgno and store it in the buffer
>> */
>> int usb_get_configuration_no(struct usb_device *dev, int cfgno,
>>                            unsigned char *buffer, int length)
>> {
>>       int result;
>>       struct usb_config_descriptor *config;
>> 
>>       config = (struct usb_config_descriptor *)&buffer[0];
>>       result = usb_get_descriptor(dev, USB_DT_CONFIG, cfgno, buffer, length);
>>       debug("get_conf_no %d Result %d, wLength %d\n", cfgno, result,
>>             le16_to_cpu(config->wTotalLength));
>>       config->wTotalLength = result; /* validated, with CPU byte order */
>> 
>>       return result;
>> }
>> 
>> (I'll skip more nested routine usage.)
>> 
>> 
>> We apparently do not have enough output enabled to see the debug
>> routine's output. We are seeing the printf output.
>> 
>> There might be a way to set the output message levels while at a
>> U-Boot prompt, up to the maximum compiled in. But it may also be
>> that we would need, say,
>> 
>> CONFIG_LOG_MAX_LEVEL=8
>> 
>> instead of the 7 we are now using.
> 
> 7 vs. 8 was not the issue.
> 
> I had the:
> 
> #define LOG_DDEBUG
> #define DEBUG
> 
> lines too late in the 3 usb*.c files. Moving them to
> before all the #include's in each leads to getting
> all the debug output too, at least if I set the
> default level to do so.
> 
> But if it gets far enough to make use of the USB media,
> then it reports, for example, every usb read via output
> like:
> 
> usb_read: udev 0
> 
> usb_read: dev 0 startblk 87878da0, blccnt 20 buffer 381a1200
> read10: start 87878da0 blocks 20
> COMMAND phase
> DATA phase
> STATUS phase
> usb_read: end startblk 87878dc0, blccnt 20 buffer 381a5200
> 
> 
> It is a rather large amount of output (after the failure
> point you are hitting). The output messes up the loader serial
> output. The EFI loader loading the kernel is done via
> U-Boot services and so all those reads are present. Once
> the kernel is active, U-Boot is not and the serial I/O is
> back to normal.
> 
> 
> I've included the updated usb*.c files and the rpi_arm64_fragment
> update with an extra line explicitly for setting the default
> log level.
> 

It looks like that if you remove files/patch-common_usb__storage.c
and rebuild/install the large output reporting usb reads will not
happen.


===
Mark Millard
marklmi at yahoo.com
<patch-common_usb__hub.c><patch-common_usb__storage.c><patch-common_usb.c><rpi_arm64_fragment>

===
Mark Millard
marklmi at yahoo.com