runqueue: convert deferral messages from bb.note to bb.debug

Using multiconfig to target baremetal pieces of the system and building
corresponding toolchains for them results in hundreds and hundreds of
"Deferring %s after %s" and "Deferred task %s now buildable".

To clean up the output and to reduce risk of missing important warnings,
convert these notice messages to debug messages.

Signed-off-by: Denys Dmytriyenko <denis@denix.org>
Signed-off-by: Denys Dmytriyenko <denys@konsulko.com>
---
 lib/bb/runqueue.py | 6 +++---
 1 file changed, 3 insertions(+), 3 deletions(-)

On Wed, 2023-07-05 at 21:55 +0000, Denys Dmytriyenko wrote:
> Using multiconfig to target baremetal pieces of the system and building
> corresponding toolchains for them results in hundreds and hundreds of
> "Deferring %s after %s" and "Deferred task %s now buildable".
> 
> To clean up the output and to reduce risk of missing important warnings,
> convert these notice messages to debug messages.
> 
> Signed-off-by: Denys Dmytriyenko <denis@denix.org>
> Signed-off-by: Denys Dmytriyenko <denys@konsulko.com>
> ---
>  lib/bb/runqueue.py | 6 +++---
>  1 file changed, 3 insertions(+), 3 deletions(-)
> 
> diff --git a/lib/bb/runqueue.py b/lib/bb/runqueue.py
> index 241a746e..a5164c9e 100644
> --- a/lib/bb/runqueue.py
> +++ b/lib/bb/runqueue.py
> @@ -1997,12 +1997,12 @@ class RunQueueExecute:
>                  # Allow the next deferred task to run. Any other deferred tasks should be deferred after that task.
>                  # We shouldn't allow all to run at once as it is prone to races.
>                  if not found:
> -                    bb.note("Deferred task %s now buildable" % t)
> +                    bb.debug(1, "Deferred task %s now buildable" % t)
>                      del self.sq_deferred[t]
>                      update_scenequeue_data([t], self.sqdata, self.rqdata, self.rq, self.cooker, self.stampcache, self, summary=False)
>                      found = t
>                  else:
> -                    bb.note("Deferring %s after %s" % (t, found))
> +                    bb.debug(1, "Deferring %s after %s" % (t, found))
>                      self.sq_deferred[t] = found
>  
>      def task_complete(self, task):
> @@ -2940,7 +2940,7 @@ def build_scenequeue_data(sqdata, rqdata, rq, cooker, stampcache, sqrq):
>                  sqdata.hashes[h] = tid
>              else:
>                  sqrq.sq_deferred[tid] = sqdata.hashes[h]
> -                bb.note("Deferring %s after %s" % (tid, sqdata.hashes[h]))
> +                bb.debug(1, "Deferring %s after %s" % (tid, sqdata.hashes[h]))
>  
>      update_scenequeue_data(sqdata.sq_revdeps, sqdata, rqdata, rq, cooker, stampcache, sqrq, summary=True)
>  

You realise that we've had a long standing bug in this code, which you
have run into and asked me about fixing. The only reason we were able
to fix it is due to these kinds of debug messages? Hiding them isn't
going to make that any easier in future :(.

Cheers,

Richard

On Thu, Jul 06, 2023 at 09:16:14AM +0100, Richard Purdie wrote:
> On Wed, 2023-07-05 at 21:55 +0000, Denys Dmytriyenko wrote:
> > Using multiconfig to target baremetal pieces of the system and building
> > corresponding toolchains for them results in hundreds and hundreds of
> > "Deferring %s after %s" and "Deferred task %s now buildable".
> > 
> > To clean up the output and to reduce risk of missing important warnings,
> > convert these notice messages to debug messages.
> > 
> > Signed-off-by: Denys Dmytriyenko <denis@denix.org>
> > Signed-off-by: Denys Dmytriyenko <denys@konsulko.com>
> > ---
> >  lib/bb/runqueue.py | 6 +++---
> >  1 file changed, 3 insertions(+), 3 deletions(-)
> > 
> > diff --git a/lib/bb/runqueue.py b/lib/bb/runqueue.py
> > index 241a746e..a5164c9e 100644
> > --- a/lib/bb/runqueue.py
> > +++ b/lib/bb/runqueue.py
> > @@ -1997,12 +1997,12 @@ class RunQueueExecute:
> >                  # Allow the next deferred task to run. Any other deferred tasks should be deferred after that task.
> >                  # We shouldn't allow all to run at once as it is prone to races.
> >                  if not found:
> > -                    bb.note("Deferred task %s now buildable" % t)
> > +                    bb.debug(1, "Deferred task %s now buildable" % t)
> >                      del self.sq_deferred[t]
> >                      update_scenequeue_data([t], self.sqdata, self.rqdata, self.rq, self.cooker, self.stampcache, self, summary=False)
> >                      found = t
> >                  else:
> > -                    bb.note("Deferring %s after %s" % (t, found))
> > +                    bb.debug(1, "Deferring %s after %s" % (t, found))
> >                      self.sq_deferred[t] = found
> >  
> >      def task_complete(self, task):
> > @@ -2940,7 +2940,7 @@ def build_scenequeue_data(sqdata, rqdata, rq, cooker, stampcache, sqrq):
> >                  sqdata.hashes[h] = tid
> >              else:
> >                  sqrq.sq_deferred[tid] = sqdata.hashes[h]
> > -                bb.note("Deferring %s after %s" % (tid, sqdata.hashes[h]))
> > +                bb.debug(1, "Deferring %s after %s" % (tid, sqdata.hashes[h]))
> >  
> >      update_scenequeue_data(sqdata.sq_revdeps, sqdata, rqdata, rq, cooker, stampcache, sqrq, summary=True)
> >  
> 
> You realise that we've had a long standing bug in this code, which you
> have run into and asked me about fixing. The only reason we were able
> to fix it is due to these kinds of debug messages? Hiding them isn't
> going to make that any easier in future :(.

Hey, you should be off this week! That means no mailing lists either :)

Seriously though, I do realize the irony here - on one hand, I really 
appreciate you finally being able to root cause and fix this long standing 
issue with the help of those debug messages, thank you! But on the other 
hand, there were already a lot of "Deferring %s after %s" messages before, 
and now the amount has doubled with "Deferred task %s now buildable" being 
added, resulting in a very clutterred output. Not every scrollback buffer 
can hold them, easily losing early parse warnings.

Yes, these messages are very useful for debugging purposes and I'm not 
suggesting to remove or hide them, simply redirect them to the debug output 
instead of default stdout, just a -D flag away. But since it's a cosmetic 
change and if you feel strongly against it, that should be fine too.