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.sch...@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.

Enabling DM_WARN actually changes the loglevel of dm_warn calls from debug to warning, c.f. https://elixir.bootlin.com/u-boot/v2024.07/source/include/dm/util.h#L11

There seems to be no available dm-specific log function other than dm_warn at the moment.

The issue I had was that in order to be able to see those messages, I had to to select DM_DEBUG, which does much more than just enabling the debug log level to be printed and eventually makes my boot unsuccessful (see original commit message), which is not acceptable :)

Can you explain what you're trying to achieve with DM_WARN enabled so we have some idea how to properly fix address your concern?

In the short term, i guess we could simply define a dm_dbg macros which does
log(LOGC_DM, LOGL_DEBUG, ##fmt)
which would also replace those instances of log(LOGC_DM, LOGL_DEBUG, in drivers/core/uclass.c.

However this means that all those messages would only be available if we reach the global log level to debug, which is very verbose. I have not looked deeply into all those messages and their contexts and wouldn't be able to quickly differentiate a debug message from a warn message, so replacing only some of them is not a small thing to do and is error prone.

I guess what we could do is have some sort of kconfig option for log level per logging category? Or in some way define log filters at compile time?

I'm not entirely sure how to go forward with this.

[...]

@@ -508,17 +509,17 @@ int of_read_u16(const struct device_node *np, const char 
*propname, u16 *outp)
  {
        const __be16 *val;
- debug("%s: %s: ", __func__, propname);
+       dm_warn("%s: %s: ", __func__, propname);

This is no warning at all.  And there are tons of those changed by
this patch.  It ended up in master as 6afdb1585112 ("dm: core: migrate
debug() messages to use dm_warn") by the way.  Please review again and
assign reasonable log levels for all converted messages, otherwise
the destinction between DM_WARN and DM_DEBUG is useless?


They are not exactly related, that's the issue. DM_DEBUG is not about the log level, it's about enabling all debug functionalities (of which is enabling the debug() calls), which renders the boot unsuccessful on my machine (see original commit message).

The second issue is, we could assign different log levels for DM, but they would be printed only if the global log level would be raised above the level of said DM log message's level. This means to see those I would need to see ALL debug messages using the logging framework. I think something more finegrained would be much more useful, but that's also not a 5min thing to do I guess.

Thank you for testing an RC though and filing a report, not many people do (me included) and we end up fixing a lot of stuff in the early days of a new release which is not the ideal workflow :)

Cheers,
Quentin

Reply via email to