[PATCH v2 3/4] dm: core: migrate debug() messages to use dm_warn

[Simon Glass]

Hi,

On Wed, 2 Oct 2024 at 09:54, Tom Rini <trini at konsulko.com> wrote:
>
> On Wed, Oct 02, 2024 at 11:13:14AM -0400, Sean Anderson wrote:
> > On 10/2/24 05:25, Quentin Schulz wrote:
> > > Hi Alexander,
> > >
> > > On 10/2/24 10:37 AM, Alexander Dahl wrote:
> > > > Hello Quentin,
> > > >
> > > > sorry for being late to the party, but I just tested v2024.10-rc6 and
> > > > my console output looks like this now:
> > > >
> > > >      ofnode_read_bool: bootph-all: true
> > > >      ofnode_read_u32_array: ranges: ofnode_read_bool: bootph-all: false
> > > >      ofnode_read_bool: bootph-some-ram: false
> > > >      ofnode_read_bool: bootph-pre-ram: false
> > > >      ofnode_read_bool: bootph-pre-sram: false
> > > >      ofnode_read_bool: u-boot,dm-pre-reloc: false
> > > >      ofnode_read_bool: u-boot,dm-pre-proper: false
> > > >      ofnode_read_bool: u-boot,dm-spl: false
> > > >      ofnode_read_bool: u-boot,dm-tpl: false
> > > >      ofnode_read_bool: u-boot,dm-vpl: false
> > > >      ofnode_read_bool: bootph-all: false
> > > >      ofnode_read_bool: bootph-some-ram: false
> > > >      ofnode_read_bool: bootph-pre-ram: false
> > > >      ofnode_read_bool: bootph-pre-sram: false
> > > >      ofnode_read_bool: u-boot,dm-pre-reloc: false
> > > >      ofnode_read_bool: u-boot,dm-pre-proper: false
> > > >      ofnode_read_bool: u-boot,dm-spl: false
> > > >      ofnode_read_bool: u-boot,dm-tpl: false
> > > >      ofnode_read_bool: u-boot,dm-vpl: false
> > > >      ofnode_read_bool: bootph-all: true
> > > >      ofnode_read_u32_array: ranges: ofnode_read_bool: bootph-all: true
> > > >      ofnode_read_u32_array: ranges: ofnode_read_bool: bootph-all: true
> > > >      ofnode_read_bool: bootph-all: true
> > > >      ofnode_read_bool: bootph-all: false
> > > >      …
> > > >
> > > > This goes on for several screen pages, and clutters the usual output.
> > > > I first thought I messed up CONFIG_LOGLEVEL or CONFIG_LOG, but no.
> > > > All I had done was setting CONFIG_DM_WARN …
> > > >
> > > > Am Tue, Jun 11, 2024 at 03:04:26PM +0200 schrieb Quentin Schulz:
> > > > > From: Quentin Schulz <quentin.schulz at cherry.de>
> > > > >
> > > > > Prior to that, seeing the debug() messages required to enable DM_DEBUG
> > > > > which defines DEBUG (and then _DEBUG) which in turn makes failing
> > > > > assert() calls reset U-Boot which isn't necessarily what is desired.
> > > > >
> > > > > Instead, let's migrate to dm_warn which is using log_debug when unset or
> > > > > log_warn when set.
> > > > >
> > > > > While at it, reword the DM_DEBUG symbol in Kconfig to explain what it
> > > > > now actually does.
> > > >
> > > > CONFIG_DM_WARN currently reads like this:
> > > >
> > > >      Enable this to see warnings related to driver model.
> > > >
> > > >      Warnings may help with debugging, such as when expected devices do
> > > >      not bind correctly. If the option is disabled, dm_warn() is compiled
> > > >      out - it will do nothing when called.
> > > >
> > > > Instead of just useful warnings, users get debug messages all over the
> > > > place now.  Is this actually intended behaviour?  Can this be fixed
> > > > before v2024.10 release please?
> > > >
> > >
> > > There are basically less than 3 working days left before v2024.10 is released and I'm inclined to say this is annoying rather than a bug, so I am not entirely sure this will 1) make it in time if we agree on a fix (needs to include review process in those 3 working days) 2) be acceptable for a late addition in the release cycle. Let's try though, maybe we can figure something out.
> >
> > This is a bug. Printing this many messages will have a major impact on boot times.
> >
> > A config going from "may print out a few more lines of extra info" to "firehose"
> > is very surprising to users (as evidenced by Alexander's email).
> >
> > If you can't figure out which lines to disable, I recommend simply reverting the
> > patch.
>
> Checking this myself too, no platforms enable this by default. So I
> believe we do need to improve the situation here, but I don't think we
> need to revert this for release.

I think the problem is that the dm_warn() thing went a bit too far.

For example, ofnode_read_u8() should not warn unless something goes
wrong, but when it was log_debug() it would show everything.

So in that case, the first and last dm_warn() should change back to
log_debug(). The middle one should be expanded to show the node name
and (strictly speaking) it should only show the node name if _DEBUG is
0. Eek.

Not a release-blocker IMO, but it does suggest that adding a CI test
for DM_WARN would be useful. We have a few of these already, e.g.
'sandbox_noinst with LOAD_FIT_FULL test.py'

Regards,
Simon