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

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.


===
Mark Millard
marklmi at yahoo.com