[PATCH 0/4] test: uncover NULL dereferences in logging

Setting CONFIG_LOG_MAX_LEVEL=9 in sandbox_defconfig exposed to NULL dereferences and bugs in the log tests.
log_debug() statements are only executed for CONFIG_LOG_MAX_LEVEL > 6. We should have a defconfig that exposes problems in these statements.
Heinrich Schuchardt (4): dm: avoid NULL dereference in add_item() test: fix log tests dm: avoid NULL dereference in lists_bind_fdt() configs: sandbox_defconfig: CONFIG_LOG_MAX_LEVEL=9
configs/sandbox_defconfig | 2 ++ drivers/core/acpi.c | 4 ++-- drivers/core/lists.c | 7 ++++--- test/log/log_test.c | 11 +++++++---- 4 files changed, 15 insertions(+), 9 deletions(-)

acpi_add_other_item() passes dev = NULL. Instead of dev->name write the string "other" to the debug log:
ACPI: Writing ACPI tables at 1fd3000 0base: writing table '<NULL>' * other: Added type 3, 0000000011fd4000, size 240 1facs: writing table 'FACS' * other: Added type 3, 0000000011fd4240, size 40 5csrt: writing table 'CSRT' * other: Added type 3, 0000000011fd4280, size 30
Signed-off-by: Heinrich Schuchardt heinrich.schuchardt@canonical.com --- Resent --- drivers/core/acpi.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-)
diff --git a/drivers/core/acpi.c b/drivers/core/acpi.c index 0df58dbc0d..8457733edb 100644 --- a/drivers/core/acpi.c +++ b/drivers/core/acpi.c @@ -159,8 +159,8 @@ static int add_item(struct acpi_ctx *ctx, struct udevice *dev, memcpy(item->buf, start, item->size); } item_count++; - log_debug("* %s: Added type %d, %p, size %x\n", dev->name, type, start, - item->size); + log_debug("* %s: Added type %d, %p, size %x\n", + dev ? dev->name : "other", type, start, item->size);
return 0; }

Consider CONFIG_LOG_MAX_LEVEL and gd->default_log_level in
* do_log_test_helpers() * log_test_dropped() * log_test_level_deny()
Signed-off-by: Heinrich Schuchardt heinrich.schuchardt@canonical.com --- test/log/log_test.c | 11 +++++++---- 1 file changed, 7 insertions(+), 4 deletions(-)
diff --git a/test/log/log_test.c b/test/log/log_test.c index db7170f304..c5abff80d1 100644 --- a/test/log/log_test.c +++ b/test/log/log_test.c @@ -277,7 +277,7 @@ int do_log_test_helpers(struct unit_test_state *uts) log_content("level %d\n", LOGL_DEBUG_CONTENT); log_io("level %d\n", LOGL_DEBUG_IO);
- for (i = LOGL_EMERG; i <= _LOG_MAX_LEVEL; i++) + for (i = LOGL_EMERG; i <= gd->default_log_level; i++) ut_assert_nextline("%*s() level %d", CONFIG_LOGF_FUNC_PAD, __func__, i); ut_assert_console_end(); @@ -381,7 +381,8 @@ int log_test_level_deny(struct unit_test_state *uts) ut_assertok(console_record_reset_enable()); log_run(); check_log_entries_flags_levels(EXPECT_LOG | EXPECT_DIRECT | EXPECT_FORCE, - LOGL_WARNING + 1, _LOG_MAX_LEVEL); + LOGL_WARNING + 1, + min(gd->default_log_level, LOGL_INFO));
ut_assertok(log_remove_filter("console", filt1)); ut_assertok(log_remove_filter("console", filt2)); @@ -420,9 +421,11 @@ int log_test_dropped(struct unit_test_state *uts) gd->log_drop_count = 0;
ut_assertok(console_record_reset_enable()); - log_run();
- ut_asserteq(gd->log_drop_count, 3 * (LOGL_COUNT - LOGL_FIRST - 1)); + log_run(); + ut_asserteq(2 * (LOGL_COUNT - LOGL_FIRST) + + _LOG_MAX_LEVEL - LOGL_FIRST + 1, + gd->log_drop_count); check_log_entries_flags_levels(EXPECT_DEBUG, LOGL_FIRST, CONFIG_LOG_DEFAULT_LEVEL);
gd->flags |= GD_FLG_LOG_READY;

On Mon, 11 Jul 2022 at 00:21, Heinrich Schuchardt heinrich.schuchardt@canonical.com wrote:
Consider CONFIG_LOG_MAX_LEVEL and gd->default_log_level in
- do_log_test_helpers()
- log_test_dropped()
- log_test_level_deny()
Signed-off-by: Heinrich Schuchardt heinrich.schuchardt@canonical.com
test/log/log_test.c | 11 +++++++---- 1 file changed, 7 insertions(+), 4 deletions(-)
Reviewed-by: Simon Glass sjg@chromium.org

On Mon, 11 Jul 2022 at 00:21, Heinrich Schuchardt heinrich.schuchardt@canonical.com wrote:
Consider CONFIG_LOG_MAX_LEVEL and gd->default_log_level in
- do_log_test_helpers()
- log_test_dropped()
- log_test_level_deny()
Signed-off-by: Heinrich Schuchardt heinrich.schuchardt@canonical.com
test/log/log_test.c | 11 +++++++---- 1 file changed, 7 insertions(+), 4 deletions(-)
Reviewed-by: Simon Glass sjg@chromium.org
Applied to u-boot-dm, thanks!

If parameter drv of lists_bind_fdt() is specified, we want to bind to this specific driver even if its field of_match is NULL.
If entry->of_match is NULL, we should not dereference it in a debug statement.
Fixes: d3e773613b6d ("dm: core: Use U-Boot logging instead of pr_debug()") Signed-off-by: Heinrich Schuchardt heinrich.schuchardt@canonical.com --- drivers/core/lists.c | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-)
diff --git a/drivers/core/lists.c b/drivers/core/lists.c index 22ccd9faaa..93514a744d 100644 --- a/drivers/core/lists.c +++ b/drivers/core/lists.c @@ -241,9 +241,10 @@ int lists_bind_fdt(struct udevice *parent, ofnode node, struct udevice **devp, } }
- log_debug(" - found match at '%s': '%s' matches '%s'\n", - entry->name, entry->of_match->compatible, - id->compatible); + if (entry->of_match) + log_debug(" - found match at '%s': '%s' matches '%s'\n", + entry->name, entry->of_match->compatible, + id->compatible); ret = device_bind_with_driver_data(parent, entry, name, id->data, node, &dev); if (ret == -ENODEV) {

On Mon, 11 Jul 2022 at 00:21, Heinrich Schuchardt heinrich.schuchardt@canonical.com wrote:
If parameter drv of lists_bind_fdt() is specified, we want to bind to this specific driver even if its field of_match is NULL.
If entry->of_match is NULL, we should not dereference it in a debug statement.
Fixes: d3e773613b6d ("dm: core: Use U-Boot logging instead of pr_debug()") Signed-off-by: Heinrich Schuchardt heinrich.schuchardt@canonical.com
drivers/core/lists.c | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-)
Reviewed-by: Simon Glass sjg@chromium.org

On Mon, 11 Jul 2022 at 00:21, Heinrich Schuchardt heinrich.schuchardt@canonical.com wrote:
If parameter drv of lists_bind_fdt() is specified, we want to bind to this specific driver even if its field of_match is NULL.
If entry->of_match is NULL, we should not dereference it in a debug statement.
Fixes: d3e773613b6d ("dm: core: Use U-Boot logging instead of pr_debug()") Signed-off-by: Heinrich Schuchardt heinrich.schuchardt@canonical.com
drivers/core/lists.c | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-)
Reviewed-by: Simon Glass sjg@chromium.org
Applied to u-boot-dm, thanks!

Without setting CONFIG_LOG_MAX_LEVEL to a value above 6 we will not detect NULL dereferences and other errors in log_debug() calls.
Signed-off-by: Heinrich Schuchardt heinrich.schuchardt@canonical.com --- Resent --- configs/sandbox_defconfig | 2 ++ 1 file changed, 2 insertions(+)
diff --git a/configs/sandbox_defconfig b/configs/sandbox_defconfig index c509a924e6..4b87d96c76 100644 --- a/configs/sandbox_defconfig +++ b/configs/sandbox_defconfig @@ -31,6 +31,8 @@ CONFIG_CONSOLE_RECORD=y CONFIG_CONSOLE_RECORD_OUT_SIZE=0x6000 CONFIG_PRE_CONSOLE_BUFFER=y CONFIG_LOG=y +CONFIG_LOG_MAX_LEVEL=9 +CONFIG_LOG_DEFAULT_LEVEL=6 CONFIG_DISPLAY_BOARDINFO_LATE=y CONFIG_STACKPROTECTOR=y CONFIG_ANDROID_AB=y

On Mon, 11 Jul 2022 at 00:21, Heinrich Schuchardt heinrich.schuchardt@canonical.com wrote:
Without setting CONFIG_LOG_MAX_LEVEL to a value above 6 we will not detect NULL dereferences and other errors in log_debug() calls.
Signed-off-by: Heinrich Schuchardt heinrich.schuchardt@canonical.com
Resent
configs/sandbox_defconfig | 2 ++ 1 file changed, 2 insertions(+)
Reviewed-by: Simon Glass sjg@chromium.org

On Mon, 11 Jul 2022 at 00:21, Heinrich Schuchardt heinrich.schuchardt@canonical.com wrote:
Without setting CONFIG_LOG_MAX_LEVEL to a value above 6 we will not detect NULL dereferences and other errors in log_debug() calls.
Signed-off-by: Heinrich Schuchardt heinrich.schuchardt@canonical.com
Resent
configs/sandbox_defconfig | 2 ++ 1 file changed, 2 insertions(+)
Reviewed-by: Simon Glass sjg@chromium.org
Applied to u-boot-dm, thanks!
participants (2)
-
Heinrich Schuchardt
-
Simon Glass