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

From: Mark Millard <marklmi_at_yahoo.com>
Date: Fri, 30 Sep 2022 04:51:31 UTC
On 2022-Sep-29, at 21:11, Mark Millard <marklmi@yahoo.com> wrote:

> On 2022-Sep-29, at 19:14, Mark Millard <marklmi@yahoo.com> wrote:
> 
>> On 2022-Sep-29, at 17:27, bob prohaska <fbsd@www.zefox.net> wrote:
>> 
>>> . . .
>> U-Boot> run bootcmd_usb0
>> 
>> Device 0: 
>> usb_read: udev 0
>> 
>> usb_read: dev 0 startblk 0, blccnt 1 buffer 3af42c00
>> read10: start 0 blocks 1
>> COMMAND phase
>> DATA phase
>> usb_bulk_msg error status 0
> 
> Looks like the above is from:
> 
>        result = usb_bulk_msg(us->pusb_dev, pipe, srb->pdata, srb->datalen,
>                              &data_actlen, USB_CNTL_TIMEOUT * 5);
>        /* special handling of STALL in DATA phase */
>        if ((result < 0) && (us->pusb_dev->status & USB_ST_STALLED)) {
>                . . .
>        }
>        if (result < 0) {
>                debug("usb_bulk_msg error status %ld\n",
>                      us->pusb_dev->status);
>                usb_stor_BBB_reset(us);
>                return USB_STOR_TRANSPORT_FAILED;
>        }
> 
> (result's value seems to not be reported.)
> 
> The above code's usb_stor_BBB_reset use initiated the below:
> 
>> BBB_reset
>> usb_control_msg: request: 0xFF, requesttype: 0x21, value 0x0 index 0x0 length 0x0
>> BBB_reset result -110: status 0 reset
>> usb_control_msg: request: 0x1, requesttype: 0x2, value 0x0 index 0x81 length 0x0
>> BBB_reset result -22: status 0 clearing IN endpoint
>> usb_control_msg: request: 0x1, requesttype: 0x2, value 0x0 index 0x2 length 0x0
>> BBB_reset result -22: status 0 clearing OUT endpoint
>> BBB_reset done
> 
> Looks like -110 is from a:      return -ETIMEDOUT;
> 
> Looks like each -22 is from a:  return -EINVAL;
> 
> The -EINVAL results seem to be from usb_clear_halt
> doing:
> 
>        int endp = usb_pipeendpoint(pipe)|(usb_pipein(pipe)<<7);
> 
>        result = usb_control_msg(dev, usb_sndctrlpipe(dev, 0),
>                                 USB_REQ_CLEAR_FEATURE, USB_RECIP_ENDPOINT, 0,
>                                 endp, NULL, 0, USB_CNTL_TIMEOUT * 3);
> 
>        /* don't clear if failed */
>        if (result < 0)   
>                return result;
> 
> usb_clear_halt is used twice, via usb_stor_BBB_reset :
> 
>        pipe = usb_rcvbulkpipe(us->pusb_dev, us->ep_in);
>        result = usb_clear_halt(us->pusb_dev, pipe);
> 
>        pipe = usb_sndbulkpipe(us->pusb_dev, us->ep_out);
>        result = usb_clear_halt(us->pusb_dev, pipe);
> 
>> Read ERROR
> 
> This is from:
> 
> retry_it:    
>                if (smallblks == ss->max_xfer_blk)
>                        usb_show_progress();
>                srb->datalen = block_dev->blksz * smallblks;
>                srb->pdata = (unsigned char *)buf_addr;
>                if (usb_read_10(srb, ss, start, smallblks)) {
>                        debug("Read ERROR\n");
>                        ss->flags &= ~USB_READY;
>                        usb_request_sense(srb, ss);
>                        if (retry--)       
>                                goto retry_it;
>                        blkcnt -= blks;
>                        break;
>                }  
> 
> The retry_it getting to usb_read_10 again lead to:
> 
>> COMMAND phase
>> DATA phase
> 
> So it is the retry using usb_read_10 that ends up with
> the RPi3B reboot happening instead of completing.
> 
> 
> I'm not likely to manage to give this further interpretation.
> 

You generated 2 more error logs. They have (among other
things) . . .

pelorus_console.txt2_boot_loop ends with:

       scanning usb for storage devices... 1 Storage Device(s) found
U-Boot> run bootcmd_usb0

Device 0: 
usb_read: udev 0

usb_read: dev 0 startblk 0, blccnt 1 buffer 3af42c00
read10: start 0 blocks 1
COMMAND phase
DATA phase
usb_bulk_msg error status 0
BBB_reset
usb_control_msg: request: 0xFF, requesttype: 0x21, value 0x0 index 0x0 length 0x0
BBB_reset result -110: status 0 reset
usb_control_msg: request: 0x1, requesttype: 0x2, value 0x0 index 0x81 length 0x0
BBB_reset result -110: status 0 clearing IN endpoint
usb_control_msg: request: 0x1, requesttype: 0x2, value 0x0 index 0x2 length 0x0
BBB_reset result -110: status 0 clearing OUT endpoint
BBB_reset done
Read ERROR
COMMAND phase
usb_stor_BBB_comdat:usb_bulk_msg error
failed to send CBW status 0
BBB_reset
usb_control_msg: request: 0xFF, requesttype: 0x21, value 0x0 index 0x0 length 0x0
BBB_reset result -110: status 0 reset
usb_control_msg: request: 0x1, requesttype: 0x2, value 0x0 index 0x81 length 0x0
BBB_reset result -110: status 0 clearing IN endpoint
usb_control_msg: request: 0x1, requesttype: 0x2, value 0x0 index 0x2 length 0x0
BBB_reset result -110: status 0 clearing OUT endpoint
BBB_reset done
Request Sense returned 00 00 00

(Then it repeats, starting with read10 again, over and
over.)


pelorus_console_txt3_bootcmd_0_failure ends with:

       scanning usb for storage devices... 1 Storage Device(s) found
U-Boot> run bootcmd_usb0

Device 0: 
usb_read: udev 0

usb_read: dev 0 startblk 0, blccnt 1 buffer 3af42c00
read10: start 0 blocks 1
COMMAND phase
DATA phase
usb_bulk_msg error status 0
BBB_reset
usb_control_msg: request: 0xFF, requesttype: 0x21, value 0x0 index 0x0 length 0x0
BBB_reset result -22: status 0 reset
usb_control_msg: request: 0x1, requesttype: 0x2, value 0x0 index 0x81 length 0x0
BBB_reset result -22: status 0 clearing IN endpoint
usb_control_msg: request: 0x1, requesttype: 0x2, value 0x0 index 0x2 length 0x0
BBB_reset result -22: status 0 clearing OUT endpoint
BBB_reset done
Read ERROR
COMMAND phase
DATA phase

(Apparently it hung up instead of rebooting or repeating?)

So, at leasts 3 different patterns of -ETIMEDOUT and -EINVAL
results in the BBB_reset activity, each of the 3 having a
somewhat different overall behavior.

I've no clue why the mixes of -ETIMEDOUT and -EINVAL happen.

===
Mark Millard
marklmi at yahoo.com