[PATCH v4 3/4] boot: Add more debugging to iter_incr()

[Tom Rini]

On Mon, Oct 13, 2025 at 04:12:03PM +0100, Simon Glass wrote:
> Hi Tom,
> 
> On Mon, 13 Oct 2025 at 15:15, Tom Rini <trini at konsulko.com> wrote:
> >
> > On Sat, Oct 11, 2025 at 08:19:53AM +0100, Simon Glass wrote:
> > > Hi Tom,
> > >
> > > On Fri, 10 Oct 2025 at 15:35, Tom Rini <trini at konsulko.com> wrote:
> > > >
> > > > On Fri, Oct 10, 2025 at 11:36:10AM +0100, Simon Glass wrote:
> > > > > Hi Tom,
> > > > >
> > > > > On Thu, 9 Oct 2025 at 18:30, Tom Rini <trini at konsulko.com> wrote:
> > > > > >
> > > > > > On Thu, Oct 09, 2025 at 03:29:54AM -0600, Simon Glass wrote:
> > > > > >
> > > > > > > This function is the core of the bootstd iteration. Add some debugging
> > > > > > > for the decisions it makes along the way, to make it easier to track
> > > > > > > what is going on.
> > > > > > >
> > > > > > > Signed-off-by: Simon Glass <sjg at chromium.org>
> > > > > > > ---
> > > > > > >
> > > > > > > (no changes since v1)
> > > > > > >
> > > > > > >  boot/bootflow.c | 23 +++++++++++++++++++----
> > > > > > >  1 file changed, 19 insertions(+), 4 deletions(-)
> > > > > > >
> > > > > > > diff --git a/boot/bootflow.c b/boot/bootflow.c
> > > > > > > index 78df09f369d..de69e27bec7 100644
> > > > > > > --- a/boot/bootflow.c
> > > > > > > +++ b/boot/bootflow.c
> > > > > > > @@ -193,8 +193,10 @@ static int iter_incr(struct bootflow_iter *iter)
> > > > > > >       log_debug("entry: err=%d\n", iter->err);
> > > > > > >       global = iter->doing_global;
> > > > > > >
> > > > > > > -     if (iter->err == BF_NO_MORE_DEVICES)
> > > > > > > +     if (iter->err == BF_NO_MORE_DEVICES) {
> > > > > > > +             log_debug("-> err: no more devices1\n");
> > > > > > >               return BF_NO_MORE_DEVICES;
> > > > > > > +     }
> > > > > >
> > > > > > Thinking more about what I said in the previous iteration about git
> > > > > > blame history, ones like this should be log_msg_ret (the history on
> > > > > > "when did the test for == BF_NO_MORE_DEVICES come from is unchanged, but
> > > > > > now you can have debug statements when enabled).
> > > > >
> > > > > Yes we can add that as well, but I still want to have the log_debug()
> > > > > as this doesn't require enabling CONFIG_LOG_ERROR_RETURN. That feature
> > > > > produces a lot of output even in normal operation since it shows
> > > > > errors dealt with by higher level code. It is really only designed to
> > > > > find the source of a particular error when you are stuck.
> > > > >
> > > > > >
> > > > > > [snip]
> > > > > > > @@ -228,11 +234,15 @@ static int iter_incr(struct bootflow_iter *iter)
> > > > > > >
> > > > > > >       if (iter->err != BF_NO_MORE_PARTS) {
> > > > > > >               /* ...select next partition  */
> > > > > > > -             if (++iter->part <= iter->max_part)
> > > > > > > +             if (++iter->part <= iter->max_part) {
> > > > > > > +                     log_debug("-> next partition %d max %d\n", iter->part,
> > > > > > > +                               iter->max_part);
> > > > > > >                       return 0;
> > > > > > > +             }
> > > > > >
> > > > > > Shouldn't this be a debug message instead in the caller?
> > > > >
> > > > > I am trying to log_debug() every exit from this function...so you can
> > > > > see the entry and then which path it took.
> > > > >
> > > > > >
> > > > > > [snip]
> > > > > > > @@ -326,8 +336,13 @@ static int iter_incr(struct bootflow_iter *iter)
> > > > > > >       }
> > > > > > >
> > > > > > >       /* if there are no more bootdevs, give up */
> > > > > > > -     if (ret)
> > > > > > > +     if (ret) {
> > > > > > > +             log_debug("-> no more bootdevs\n");
> > > > > > >               return log_msg_ret("incr", BF_NO_MORE_DEVICES);
> > > > > > > +     }
> > > > > >
> > > > > > Then do we actually need both a log_debug and a log_msg_ret?
> > > > >
> > > > > Please see above.
> > > >
> > > > I guess my question is, but why? Is this something that's going to be
> > > > debugged frequently? Why doesn't every function have meaningful text
> > > > string log_debug messages, just in case? And then why bother with
> > > > log_msg_ret at all?
> > >
> > > I have found myself in this function quite a few times, trying to work
> > > out what it is up to, so I decided to add more debugging.
> > >
> > > Anyway, would you like to just drop this patch, or something else?
> >
> > I'd like to fix the underlying problem so that we don't have a similar
> > discussion on your next series. As yes, I think in general all of these
> > patches to add more detailed logging on top of log_msg_ret logging are
> > too much. And I gather you're debugging these problems on real hardware
> > where using some source level debugger with sandbox isn't an option?
> 
> What is the underlying problem?

Patch and code churn (and so history churn) for no functional changes
and increased reviewer load.

> The debugging was useful with the EFI app where it is sort-of possible
> to use a debugger, but is a bit painful. I ended up comparing logs to
> figure it out. Debuggers are not easy when the function being debugged
> is called dozens of times.
> 
> I can imagine it being useful when someone reports a problem with the
> iteration...we could just turn on the option and the person could post
> a dump.
> 
> Anyway, I'm happy to drop this patch.

Thanks.

-- 
Tom
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 228 bytes
Desc: not available
URL: <https://lists.denx.de/pipermail/u-boot/attachments/20251013/f1d361be/attachment.sig>