From 52d3df7fefe30b05677db9055e68c666a071d89a Mon Sep 17 00:00:00 2001 From: Simon Glass Date: Sat, 12 Sep 2020 11:13:34 -0600 Subject: [PATCH 1/9] log: Allow LOG_DEBUG to always enable log output At present if CONFIG_LOG enabled, putting LOG_DEBUG at the top of a file (before log.h inclusion) causes _log() to be executed for every log() call, regardless of the build- or run-time logging level. However there is no guarantee that the log record will actually be displayed. If the current log level is lower than LOGL_DEBUG then it will not be. Add a way to signal that the log record should always be displayed and update log_passes_filters() to handle this. With the new behaviour, log_debug() will always log if LOG_DEBUG is enabled. Move log_test_syslog_nodebug() into its own file since it cannot be made to work where it is, with LOG_DEBUG defined. Signed-off-by: Simon Glass --- common/log.c | 6 ++- doc/README.log | 7 +--- include/log.h | 18 +++++++-- test/log/Makefile | 1 + test/log/syslog_test.c | 76 +---------------------------------- test/log/syslog_test.h | 50 +++++++++++++++++++++++ test/log/syslog_test_ndebug.c | 55 +++++++++++++++++++++++++ 7 files changed, 129 insertions(+), 84 deletions(-) create mode 100644 test/log/syslog_test.h create mode 100644 test/log/syslog_test_ndebug.c diff --git a/common/log.c b/common/log.c index 9a5f100da3..ac34f1c97b 100644 --- a/common/log.c +++ b/common/log.c @@ -157,6 +157,9 @@ static bool log_passes_filters(struct log_device *ldev, struct log_rec *rec) { struct log_filter *filt; + if (rec->force_debug) + return true; + /* If there are no filters, filter on the default log level */ if (list_empty(&ldev->filter_head)) { if (rec->level > gd->default_log_level) @@ -219,7 +222,8 @@ int _log(enum log_category_t cat, enum log_level_t level, const char *file, va_list args; rec.cat = cat; - rec.level = level; + rec.level = level & LOGL_LEVEL_MASK; + rec.force_debug = level & LOGL_FORCE_DEBUG; rec.file = file; rec.line = line; rec.func = func; diff --git a/doc/README.log b/doc/README.log index ba838824a9..a313399fc9 100644 --- a/doc/README.log +++ b/doc/README.log @@ -78,11 +78,8 @@ Sometimes it is useful to turn on logging just in one file. You can use this: #define LOG_DEBUG to enable building in of all logging statements in a single file. Put it at -the top of the file, before any #includes. - -To actually get U-Boot to output this you need to also set the default logging -level - e.g. set CONFIG_LOG_DEFAULT_LEVEL to 7 (LOGL_DEBUG) or more. Otherwise -debug output is suppressed and will not be generated. +the top of the file, before any #includes. This overrides any log-level setting +in U-Boot, including CONFIG_LOG_DEFAULT_LEVEL, but just for that file. Convenience functions diff --git a/include/log.h b/include/log.h index 2859ce1f2e..86c8d7be09 100644 --- a/include/log.h +++ b/include/log.h @@ -33,6 +33,9 @@ enum log_level_t { LOGL_COUNT, LOGL_NONE, + LOGL_LEVEL_MASK = 0xf, /* Mask for valid log levels */ + LOGL_FORCE_DEBUG = 0x10, /* Mask to force output due to LOG_DEBUG */ + LOGL_FIRST = LOGL_EMERG, LOGL_MAX = LOGL_DEBUG_IO, }; @@ -133,7 +136,7 @@ static inline int _log_nop(enum log_category_t cat, enum log_level_t level, #if CONFIG_IS_ENABLED(LOG) #ifdef LOG_DEBUG -#define _LOG_DEBUG 1 +#define _LOG_DEBUG LOGL_FORCE_DEBUG #else #define _LOG_DEBUG 0 #endif @@ -141,9 +144,11 @@ static inline int _log_nop(enum log_category_t cat, enum log_level_t level, /* Emit a log record if the level is less that the maximum */ #define log(_cat, _level, _fmt, _args...) ({ \ int _l = _level; \ - if (CONFIG_IS_ENABLED(LOG) && (_l <= _LOG_MAX_LEVEL || _LOG_DEBUG)) \ - _log((enum log_category_t)(_cat), _l, __FILE__, __LINE__, \ - __func__, \ + if (CONFIG_IS_ENABLED(LOG) && \ + (_LOG_DEBUG != 0 || _l <= _LOG_MAX_LEVEL)) \ + _log((enum log_category_t)(_cat), \ + (enum log_level_t)(_l | _LOG_DEBUG), __FILE__, \ + __LINE__, __func__, \ pr_fmt(_fmt), ##_args); \ }) #else @@ -279,8 +284,12 @@ void __assert_fail(const char *assertion, const char *file, unsigned int line, * Memebers marked as 'allocated' are allocated (e.g. via strdup()) by the log * system. * + * TODO(sjg@chromium.org): Compress this struct down a bit to reduce space, e.g. + * a single u32 for cat, level, line and force_debug + * * @cat: Category, representing a uclass or part of U-Boot * @level: Severity level, less severe is higher + * @force_debug: Force output of debug * @file: Name of file where the log record was generated (not allocated) * @line: Line number where the log record was generated * @func: Function where the log record was generated (not allocated) @@ -289,6 +298,7 @@ void __assert_fail(const char *assertion, const char *file, unsigned int line, struct log_rec { enum log_category_t cat; enum log_level_t level; + bool force_debug; const char *file; int line; const char *func; diff --git a/test/log/Makefile b/test/log/Makefile index 4c92550f6e..52e2f7b41c 100644 --- a/test/log/Makefile +++ b/test/log/Makefile @@ -10,6 +10,7 @@ obj-y += test-main.o ifdef CONFIG_SANDBOX obj-$(CONFIG_LOG_SYSLOG) += syslog_test.o +obj-$(CONFIG_LOG_SYSLOG) += syslog_test_ndebug.o endif ifndef CONFIG_LOG diff --git a/test/log/syslog_test.c b/test/log/syslog_test.c index 120a8b2537..abcb9ffd28 100644 --- a/test/log/syslog_test.c +++ b/test/log/syslog_test.c @@ -18,48 +18,11 @@ #include #include #include +#include DECLARE_GLOBAL_DATA_PTR; -#define LOGF_TEST (BIT(LOGF_FUNC) | BIT(LOGF_MSG)) - -/** - * struct sb_log_env - private data for sandbox ethernet driver - * - * This structure is used for the private data of the sandbox ethernet - * driver. - * - * @expected: string expected to be written by the syslog driver - * @uts: unit test state - */ -struct sb_log_env { - const char *expected; - struct unit_test_state *uts; -}; - -/** - * sb_log_tx_handler() - transmit callback function - * - * This callback function is invoked when a network package is sent using the - * sandbox Ethernet driver. The private data of the driver holds a sb_log_env - * structure with the unit test state and the expected UDP payload. - * - * The following checks are executed: - * - * * the Ethernet packet indicates a IP broadcast message - * * the IP header is for a local UDP broadcast message to port 514 - * * the UDP payload matches the expected string - * - * After testing the pointer to the expected string is set to NULL to signal - * that the callback function has been called. - * - * @dev: sandbox ethernet device - * @packet: Ethernet packet - * @len: length of Ethernet packet - * Return: 0 = success - */ -static int sb_log_tx_handler(struct udevice *dev, void *packet, - unsigned int len) +int sb_log_tx_handler(struct udevice *dev, void *packet, unsigned int len) { struct eth_sandbox_priv *priv = dev_get_priv(dev); struct sb_log_env *env = priv->priv; @@ -251,38 +214,3 @@ static int log_test_syslog_debug(struct unit_test_state *uts) return 0; } LOG_TEST(log_test_syslog_debug); - -/** - * log_test_syslog_nodebug() - test logging level filter - * - * Verify that log_debug() does not lead to a log message if the logging level - * is set to LOGL_INFO. - * - * @uts: unit test state - * Return: 0 = success - */ -static int log_test_syslog_nodebug(struct unit_test_state *uts) -{ - int old_log_level = gd->default_log_level; - struct sb_log_env env; - - gd->log_fmt = LOGF_TEST; - gd->default_log_level = LOGL_INFO; - env_set("ethact", "eth@10002000"); - env_set("log_hostname", "sandbox"); - env.expected = "<7>sandbox uboot: log_test_syslog_nodebug() " - "testing log_debug\n"; - env.uts = uts; - sandbox_eth_set_tx_handler(0, sb_log_tx_handler); - /* Used by ut_assert macros in the tx_handler */ - sandbox_eth_set_priv(0, &env); - log_debug("testing %s\n", "log_debug"); - sandbox_eth_set_tx_handler(0, NULL); - /* Check that the callback function was not called */ - ut_assertnonnull(env.expected); - gd->default_log_level = old_log_level; - gd->log_fmt = log_get_default_format(); - - return 0; -} -LOG_TEST(log_test_syslog_nodebug); diff --git a/test/log/syslog_test.h b/test/log/syslog_test.h new file mode 100644 index 0000000000..75900f3aad --- /dev/null +++ b/test/log/syslog_test.h @@ -0,0 +1,50 @@ +/* SPDX-License-Identifier: GPL-2.0+ */ +/* + * Copyright (c) 2020, Heinrich Schuchardt + * + * Header file for logging tests + */ + +#ifndef __SYSLOG_TEST_H +#define __SYSLOG_TEST_H + +#define LOGF_TEST (BIT(LOGF_FUNC) | BIT(LOGF_MSG)) + +/** + * struct sb_log_env - private data for sandbox ethernet driver + * + * This structure is used for the private data of the sandbox ethernet + * driver. + * + * @expected: string expected to be written by the syslog driver + * @uts: unit test state + */ +struct sb_log_env { + const char *expected; + struct unit_test_state *uts; +}; + +/** + * sb_log_tx_handler() - transmit callback function + * + * This callback function is invoked when a network package is sent using the + * sandbox Ethernet driver. The private data of the driver holds a sb_log_env + * structure with the unit test state and the expected UDP payload. + * + * The following checks are executed: + * + * * the Ethernet packet indicates a IP broadcast message + * * the IP header is for a local UDP broadcast message to port 514 + * * the UDP payload matches the expected string + * + * After testing the pointer to the expected string is set to NULL to signal + * that the callback function has been called. + * + * @dev: sandbox ethernet device + * @packet: Ethernet packet + * @len: length of Ethernet packet + * Return: 0 = success + */ +int sb_log_tx_handler(struct udevice *dev, void *packet, unsigned int len); + +#endif diff --git a/test/log/syslog_test_ndebug.c b/test/log/syslog_test_ndebug.c new file mode 100644 index 0000000000..7815977ea2 --- /dev/null +++ b/test/log/syslog_test_ndebug.c @@ -0,0 +1,55 @@ +// SPDX-License-Identifier: GPL-2.0+ +/* + * Copyright (c) 2020, Heinrich Schuchardt + * + * Logging function tests for CONFIG_LOG_SYSLOG=y. + * + * Invoke the test with: ./u-boot -d arch/sandbox/dts/test.dtb + */ + +#include +#include +#include +#include +#include +#include +#include +#include +#include + +DECLARE_GLOBAL_DATA_PTR; + +/** + * log_test_syslog_nodebug() - test logging level filter + * + * Verify that log_debug() does not lead to a log message if the logging level + * is set to LOGL_INFO. + * + * @uts: unit test state + * Return: 0 = success + */ +static int log_test_syslog_nodebug(struct unit_test_state *uts) +{ + int old_log_level = gd->default_log_level; + struct sb_log_env env; + + gd->log_fmt = LOGF_TEST; + gd->default_log_level = LOGL_INFO; + env_set("ethact", "eth@10002000"); + env_set("log_hostname", "sandbox"); + env.expected = "<7>sandbox uboot: log_test_syslog_nodebug() " + "testing log_debug\n"; + env.uts = uts; + sandbox_eth_set_tx_handler(0, sb_log_tx_handler); + /* Used by ut_assert macros in the tx_handler */ + sandbox_eth_set_priv(0, &env); + log_debug("testing %s\n", "log_debug"); + sandbox_eth_set_tx_handler(0, NULL); + /* Check that the callback function was not called */ + ut_assertnonnull(env.expected); + gd->default_log_level = old_log_level; + gd->log_fmt = log_get_default_format(); + + return 0; +} +LOG_TEST(log_test_syslog_nodebug); From 26637e2e4c7235e4fe01b78a9646471c65e28aea Mon Sep 17 00:00:00 2001 From: Simon Glass Date: Sat, 12 Sep 2020 11:13:35 -0600 Subject: [PATCH 2/9] lib: Allow hexdump to be used in SPL It is sometimes useful to output hex dumps in SPL. Add a config option to allow this. Signed-off-by: Simon Glass Reviewed-by: Stefan Roese --- lib/Kconfig | 8 ++++++++ 1 file changed, 8 insertions(+) diff --git a/lib/Kconfig b/lib/Kconfig index 8efb154f73..37aae73a26 100644 --- a/lib/Kconfig +++ b/lib/Kconfig @@ -542,6 +542,14 @@ config HEXDUMP help This enables functions for printing dumps of binary data. +config SPL_HEXDUMP + bool "Enable hexdump in SPL" + depends on HEXDUMP + default y + help + This enables functions for printing dumps of binary data in + SPL. + config OF_LIBFDT bool "Enable the FDT library" default y if OF_CONTROL From b45203004ec3f3e5a259e68eddb3eb572d37f56d Mon Sep 17 00:00:00 2001 From: Simon Glass Date: Sat, 12 Sep 2020 12:28:47 -0600 Subject: [PATCH 3/9] log: Add a flag to enable log drivers At present there is no way to disable a log driver. But the syslog driver causes (attempted) network traffic in sandbox every time a log message is printed, which is often. Add a flag to enable a log driver. Adjust struct log_device to use a short for next_filter_num so that no more memory is used for devices. Also fix a missing line in the struct log_driver comment while here. To maintain compatibility, enable it for all drivers for now. Signed-off-by: Simon Glass --- common/log.c | 4 +++- common/log_console.c | 1 + common/log_syslog.c | 1 + include/log.h | 11 ++++++++++- 4 files changed, 15 insertions(+), 2 deletions(-) diff --git a/common/log.c b/common/log.c index ac34f1c97b..d6dfabb09a 100644 --- a/common/log.c +++ b/common/log.c @@ -207,7 +207,8 @@ static int log_dispatch(struct log_rec *rec) /* Emit message */ processing_msg = 1; list_for_each_entry(ldev, &gd->log_head, sibling_node) { - if (log_passes_filters(ldev, rec)) + if ((ldev->flags & LOGDF_ENABLE) && + log_passes_filters(ldev, rec)) ldev->drv->emit(ldev, rec); } processing_msg = 0; @@ -329,6 +330,7 @@ int log_init(void) } INIT_LIST_HEAD(&ldev->filter_head); ldev->drv = drv; + ldev->flags = drv->flags; list_add_tail(&ldev->sibling_node, (struct list_head *)&gd->log_head); drv++; diff --git a/common/log_console.c b/common/log_console.c index bb3f8464b9..8776fd4703 100644 --- a/common/log_console.c +++ b/common/log_console.c @@ -44,4 +44,5 @@ static int log_console_emit(struct log_device *ldev, struct log_rec *rec) LOG_DRIVER(console) = { .name = "console", .emit = log_console_emit, + .flags = LOGDF_ENABLE, }; diff --git a/common/log_syslog.c b/common/log_syslog.c index 2ae703fed7..8276883780 100644 --- a/common/log_syslog.c +++ b/common/log_syslog.c @@ -107,4 +107,5 @@ out: LOG_DRIVER(syslog) = { .name = "syslog", .emit = log_syslog_emit, + .flags = LOGDF_ENABLE, }; diff --git a/include/log.h b/include/log.h index 86c8d7be09..d28bc1ef0e 100644 --- a/include/log.h +++ b/include/log.h @@ -307,10 +307,16 @@ struct log_rec { struct log_device; +enum log_device_flags { + LOGDF_ENABLE = BIT(0), /* Device is enabled */ +}; + /** * struct log_driver - a driver which accepts and processes log records * * @name: Name of driver + * @emit: Method to call to emit a log record via this device + * @flags: Initial value for flags (use LOGDF_ENABLE to enable on start-up) */ struct log_driver { const char *name; @@ -321,6 +327,7 @@ struct log_driver { * for processing. The filter is checked before calling this function. */ int (*emit)(struct log_device *ldev, struct log_rec *rec); + unsigned short flags; }; /** @@ -333,12 +340,14 @@ struct log_driver { * @next_filter_num: Seqence number of next filter filter added (0=no filters * yet). This increments with each new filter on the device, but never * decrements + * @flags: Flags for this filter (enum log_device_flags) * @drv: Pointer to driver for this device * @filter_head: List of filters for this device * @sibling_node: Next device in the list of all devices */ struct log_device { - int next_filter_num; + unsigned short next_filter_num; + unsigned short flags; struct log_driver *drv; struct list_head filter_head; struct list_head sibling_node; From bd180db2cc73c7dc00076b0517978a8cdd557519 Mon Sep 17 00:00:00 2001 From: Simon Glass Date: Sat, 12 Sep 2020 12:28:48 -0600 Subject: [PATCH 4/9] log: Drop #ifdef in log_test This is not needed as the Makefile only builds the file if CONFIG_LOG_TEST is enabled. Drop it. Signed-off-by: Simon Glass --- test/log/log_test.c | 2 -- 1 file changed, 2 deletions(-) diff --git a/test/log/log_test.c b/test/log/log_test.c index 4245372d65..fdee5e6757 100644 --- a/test/log/log_test.c +++ b/test/log/log_test.c @@ -201,7 +201,6 @@ static int log_test(int testnum) return 0; } -#ifdef CONFIG_LOG_TEST int do_log_test(struct cmd_tbl *cmdtp, int flag, int argc, char *const argv[]) { int testnum = 0; @@ -216,4 +215,3 @@ int do_log_test(struct cmd_tbl *cmdtp, int flag, int argc, char *const argv[]) return ret ? CMD_RET_FAILURE : 0; } -#endif From 3d03ab6361a4a2b60e84da46c547b8ace01a60eb Mon Sep 17 00:00:00 2001 From: Simon Glass Date: Sat, 12 Sep 2020 12:28:49 -0600 Subject: [PATCH 5/9] log: Add a way to enable/disable a log device At present all log devices are enabled by default. Add a function to allow devices to be disabled or enabled at runtime. Signed-off-by: Simon Glass --- common/log.c | 38 ++++++++++++++++++++++++++++++++++++++ include/log.h | 17 +++++++++++++++++ test/log/log_test.c | 7 +++++++ test/py/tests/test_log.py | 8 ++++++++ 4 files changed, 70 insertions(+) diff --git a/common/log.c b/common/log.c index d6dfabb09a..1b10f6f180 100644 --- a/common/log.c +++ b/common/log.c @@ -308,6 +308,44 @@ int log_remove_filter(const char *drv_name, int filter_num) return -ENOENT; } +/** + * log_find_device_by_drv() - Find a device by its driver + * + * @drv: Log driver + * @return Device associated with that driver, or NULL if not found + */ +static struct log_device *log_find_device_by_drv(struct log_driver *drv) +{ + struct log_device *ldev; + + list_for_each_entry(ldev, &gd->log_head, sibling_node) { + if (ldev->drv == drv) + return ldev; + } + /* + * It is quite hard to pass an invalid driver since passing an unknown + * LOG_GET_DRIVER(xxx) would normally produce a compilation error. But + * it is possible to pass NULL, for example, so this + */ + + return NULL; +} + +int log_device_set_enable(struct log_driver *drv, bool enable) +{ + struct log_device *ldev; + + ldev = log_find_device_by_drv(drv); + if (!ldev) + return -ENOENT; + if (enable) + ldev->flags |= LOGDF_ENABLE; + else + ldev->flags &= ~LOGDF_ENABLE; + + return 0; +} + int log_init(void) { struct log_driver *drv = ll_entry_start(struct log_driver, log_driver); diff --git a/include/log.h b/include/log.h index d28bc1ef0e..4acc087b2e 100644 --- a/include/log.h +++ b/include/log.h @@ -388,6 +388,10 @@ struct log_filter { #define LOG_DRIVER(_name) \ ll_entry_declare(struct log_driver, _name, log_driver) +/* Get a pointer to a given driver */ +#define LOG_GET_DRIVER(__name) \ + ll_entry_get(struct log_driver, __name, log_driver) + /** * log_get_cat_name() - Get the name of a category * @@ -465,6 +469,19 @@ int log_add_filter(const char *drv_name, enum log_category_t cat_list[], */ int log_remove_filter(const char *drv_name, int filter_num); +/** + * log_device_set_enable() - Enable or disable a log device + * + * Devices are referenced by their driver, so use LOG_GET_DRIVER(name) to pass + * the driver to this function. For example if the driver is declared with + * LOG_DRIVER(wibble) then pass LOG_GET_DRIVER(wibble) here. + * + * @drv: Driver of device to enable + * @enable: true to enable, false to disable + * @return 0 if OK, -ENOENT if the driver was not found + */ +int log_device_set_enable(struct log_driver *drv, bool enable); + #if CONFIG_IS_ENABLED(LOG) /** * log_init() - Set up the log system ready for use diff --git a/test/log/log_test.c b/test/log/log_test.c index fdee5e6757..6a60ff6be3 100644 --- a/test/log/log_test.c +++ b/test/log/log_test.c @@ -196,6 +196,13 @@ static int log_test(int testnum) log_io("level %d\n", LOGL_DEBUG_IO); break; } + case 11: + log_err("default\n"); + ret = log_device_set_enable(LOG_GET_DRIVER(console), false); + log_err("disabled\n"); + ret = log_device_set_enable(LOG_GET_DRIVER(console), true); + log_err("enabled\n"); + break; } return 0; diff --git a/test/py/tests/test_log.py b/test/py/tests/test_log.py index ddc28f19ee..275f9382d2 100644 --- a/test/py/tests/test_log.py +++ b/test/py/tests/test_log.py @@ -92,6 +92,13 @@ def test_log(u_boot_console): for i in range(7): assert 'log_test() level %d' % i == next(lines) + def test11(): + """Test use of log_device_set_enable()""" + lines = run_test(11) + assert 'log_test() default' + # disabled should not be displayed + assert 'log_test() enabled' + # TODO(sjg@chromium.org): Consider structuring this as separate tests cons = u_boot_console test0() @@ -105,6 +112,7 @@ def test_log(u_boot_console): test8() test9() test10() + test11() @pytest.mark.buildconfigspec('cmd_log') def test_log_format(u_boot_console): From c7f5b850344b1bb620f603ab7df3ee92e1fa26cf Mon Sep 17 00:00:00 2001 From: Simon Glass Date: Sat, 12 Sep 2020 12:28:50 -0600 Subject: [PATCH 6/9] log: Disable the syslog driver by default This driver interferes with other sandbox tests since it causes log output to be interspersed with "No ethernet found." messages. Disable this driver by default. Enable it for the syslog tests so that they still pass. Signed-off-by: Simon Glass --- common/log_syslog.c | 1 - test/log/syslog_test.c | 24 ++++++++++++++++++++++++ test/log/syslog_test.h | 16 ++++++++++++++++ test/log/syslog_test_ndebug.c | 2 ++ 4 files changed, 42 insertions(+), 1 deletion(-) diff --git a/common/log_syslog.c b/common/log_syslog.c index 8276883780..2ae703fed7 100644 --- a/common/log_syslog.c +++ b/common/log_syslog.c @@ -107,5 +107,4 @@ out: LOG_DRIVER(syslog) = { .name = "syslog", .emit = log_syslog_emit, - .flags = LOGDF_ENABLE, }; diff --git a/test/log/syslog_test.c b/test/log/syslog_test.c index abcb9ffd28..febaca68e8 100644 --- a/test/log/syslog_test.c +++ b/test/log/syslog_test.c @@ -56,6 +56,20 @@ int sb_log_tx_handler(struct udevice *dev, void *packet, unsigned int len) return 0; } +int syslog_test_setup(struct unit_test_state *uts) +{ + ut_assertok(log_device_set_enable(LOG_GET_DRIVER(syslog), true)); + + return 0; +} + +int syslog_test_finish(struct unit_test_state *uts) +{ + ut_assertok(log_device_set_enable(LOG_GET_DRIVER(syslog), false)); + + return 0; +} + /** * log_test_syslog_err() - test log_err() function * @@ -67,6 +81,7 @@ static int log_test_syslog_err(struct unit_test_state *uts) int old_log_level = gd->default_log_level; struct sb_log_env env; + ut_assertok(syslog_test_setup(uts)); gd->log_fmt = LOGF_TEST; gd->default_log_level = LOGL_INFO; env_set("ethact", "eth@10002000"); @@ -82,6 +97,7 @@ static int log_test_syslog_err(struct unit_test_state *uts) sandbox_eth_set_tx_handler(0, NULL); gd->default_log_level = old_log_level; gd->log_fmt = log_get_default_format(); + ut_assertok(syslog_test_finish(uts)); return 0; } @@ -98,6 +114,7 @@ static int log_test_syslog_warning(struct unit_test_state *uts) int old_log_level = gd->default_log_level; struct sb_log_env env; + ut_assertok(syslog_test_setup(uts)); gd->log_fmt = LOGF_TEST; gd->default_log_level = LOGL_INFO; env_set("ethact", "eth@10002000"); @@ -114,6 +131,7 @@ static int log_test_syslog_warning(struct unit_test_state *uts) ut_assertnull(env.expected); gd->default_log_level = old_log_level; gd->log_fmt = log_get_default_format(); + ut_assertok(syslog_test_finish(uts)); return 0; } @@ -130,6 +148,7 @@ static int log_test_syslog_notice(struct unit_test_state *uts) int old_log_level = gd->default_log_level; struct sb_log_env env; + ut_assertok(syslog_test_setup(uts)); gd->log_fmt = LOGF_TEST; gd->default_log_level = LOGL_INFO; env_set("ethact", "eth@10002000"); @@ -146,6 +165,7 @@ static int log_test_syslog_notice(struct unit_test_state *uts) ut_assertnull(env.expected); gd->default_log_level = old_log_level; gd->log_fmt = log_get_default_format(); + ut_assertok(syslog_test_finish(uts)); return 0; } @@ -162,6 +182,7 @@ static int log_test_syslog_info(struct unit_test_state *uts) int old_log_level = gd->default_log_level; struct sb_log_env env; + ut_assertok(syslog_test_setup(uts)); gd->log_fmt = LOGF_TEST; gd->default_log_level = LOGL_INFO; env_set("ethact", "eth@10002000"); @@ -178,6 +199,7 @@ static int log_test_syslog_info(struct unit_test_state *uts) ut_assertnull(env.expected); gd->default_log_level = old_log_level; gd->log_fmt = log_get_default_format(); + ut_assertok(syslog_test_finish(uts)); return 0; } @@ -194,6 +216,7 @@ static int log_test_syslog_debug(struct unit_test_state *uts) int old_log_level = gd->default_log_level; struct sb_log_env env; + ut_assertok(syslog_test_setup(uts)); gd->log_fmt = LOGF_TEST; gd->default_log_level = LOGL_DEBUG; env_set("ethact", "eth@10002000"); @@ -210,6 +233,7 @@ static int log_test_syslog_debug(struct unit_test_state *uts) ut_assertnull(env.expected); gd->default_log_level = old_log_level; gd->log_fmt = log_get_default_format(); + ut_assertok(syslog_test_finish(uts)); return 0; } diff --git a/test/log/syslog_test.h b/test/log/syslog_test.h index 75900f3aad..1310257bfe 100644 --- a/test/log/syslog_test.h +++ b/test/log/syslog_test.h @@ -47,4 +47,20 @@ struct sb_log_env { */ int sb_log_tx_handler(struct udevice *dev, void *packet, unsigned int len); +/** + * syslog_test_setup() - Enable syslog logging ready for tests + * + * @uts: Test state + * @return 0 if OK, -ENOENT if the syslog log driver is not found + */ +int syslog_test_setup(struct unit_test_state *uts); + +/** + * syslog_test_finish() - Disable syslog logging after tests + * + * @uts: Test state + * @return 0 if OK, -ENOENT if the syslog log driver is not found + */ +int syslog_test_finish(struct unit_test_state *uts); + #endif diff --git a/test/log/syslog_test_ndebug.c b/test/log/syslog_test_ndebug.c index 7815977ea2..c7f5a60861 100644 --- a/test/log/syslog_test_ndebug.c +++ b/test/log/syslog_test_ndebug.c @@ -33,6 +33,7 @@ static int log_test_syslog_nodebug(struct unit_test_state *uts) int old_log_level = gd->default_log_level; struct sb_log_env env; + ut_assertok(syslog_test_setup(uts)); gd->log_fmt = LOGF_TEST; gd->default_log_level = LOGL_INFO; env_set("ethact", "eth@10002000"); @@ -49,6 +50,7 @@ static int log_test_syslog_nodebug(struct unit_test_state *uts) ut_assertnonnull(env.expected); gd->default_log_level = old_log_level; gd->log_fmt = log_get_default_format(); + ut_assertok(syslog_test_finish(uts)); return 0; } From c3f0278e29ffae81dc24c997523a8eafba503a0c Mon Sep 17 00:00:00 2001 From: Sean Anderson Date: Sat, 12 Sep 2020 17:45:43 -0400 Subject: [PATCH 7/9] net: Expose some errors generated in net_init net_init does not always succeed, and there is no existing mechanism to discover errors. This patch allows callers of net_init (such as net_init) to handle errors. The root issue is that eth_get_dev can fail, but net_init_loop doesn't expose that. The ideal way to fix eth_get_dev would be to return an error with ERR_PTR, but there are a lot of callers, and all of them just check if it's NULL. Another approach would be to change the signature to something like int eth_get_dev(struct udevice **pdev) but that would require rewriting all of the many callers. Signed-off-by: Sean Anderson Reviewed-by: Simon Glass --- include/net.h | 2 +- net/eth-uclass.c | 3 +++ net/net.c | 15 +++++++++++---- 3 files changed, 15 insertions(+), 5 deletions(-) diff --git a/include/net.h b/include/net.h index 219107194f..778acf7da3 100644 --- a/include/net.h +++ b/include/net.h @@ -593,7 +593,7 @@ extern int net_ntp_time_offset; /* offset time from UTC */ #endif /* Initialize the network adapter */ -void net_init(void); +int net_init(void); int net_loop(enum proto_t); /* Load failed. Start again. */ diff --git a/net/eth-uclass.c b/net/eth-uclass.c index 396418eb39..4424d595f4 100644 --- a/net/eth-uclass.c +++ b/net/eth-uclass.c @@ -75,6 +75,9 @@ struct udevice *eth_get_dev(void) struct eth_uclass_priv *uc_priv; uc_priv = eth_get_uclass_priv(); + if (!uc_priv) + return NULL; + if (!uc_priv->current) eth_errno = uclass_first_device(UCLASS_ETH, &uc_priv->current); diff --git a/net/net.c b/net/net.c index 197fde3568..ad7e3b3cf8 100644 --- a/net/net.c +++ b/net/net.c @@ -338,12 +338,19 @@ void net_auto_load(void) tftp_start(TFTPGET); } -static void net_init_loop(void) +static int net_init_loop(void) { if (eth_get_dev()) memcpy(net_ethaddr, eth_get_ethaddr(), 6); + else + /* + * Not ideal, but there's no way to get the actual error, and I + * don't feel like fixing all the users of eth_get_dev to deal + * with errors. + */ + return -ENONET; - return; + return 0; } static void net_clear_handlers(void) @@ -358,7 +365,7 @@ static void net_cleanup_loop(void) net_clear_handlers(); } -void net_init(void) +int net_init(void) { static int first_call = 1; @@ -381,7 +388,7 @@ void net_init(void) first_call = 0; } - net_init_loop(); + return net_init_loop(); } /**********************************************************************/ From a4326612ac4d5235d3ccf2d3ae40cc78b877ee38 Mon Sep 17 00:00:00 2001 From: Sean Anderson Date: Sat, 12 Sep 2020 17:45:44 -0400 Subject: [PATCH 8/9] log: syslog: Handle errors in net_init Since the previous patch, net_init now exposes some errors, so check for them. Signed-off-by: Sean Anderson Reviewed-by: Simon Glass --- common/log_syslog.c | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/common/log_syslog.c b/common/log_syslog.c index 2ae703fed7..4eb09157bb 100644 --- a/common/log_syslog.c +++ b/common/log_syslog.c @@ -39,7 +39,9 @@ static int log_syslog_emit(struct log_device *ldev, struct log_rec *rec) char *log_hostname; /* Setup packet buffers */ - net_init(); + ret = net_init(); + if (ret) + return ret; /* Disable hardware and put it into the reset state */ eth_halt(); /* Set current device according to environment variables */ From 1ecb6beb95fcf3369bcd964f25d8954d048846a7 Mon Sep 17 00:00:00 2001 From: Heinrich Schuchardt Date: Mon, 14 Sep 2020 10:12:19 +0200 Subject: [PATCH 9/9] doc: remove redundant doc/README.log doc/README.log was already moved to doc/develop/logging.rst but has been recreated by an incorrect merge. Signed-off-by: Heinrich Schuchardt Reviewed-by: Simon Glass --- doc/README.log | 283 ------------------------------------------------- 1 file changed, 283 deletions(-) delete mode 100644 doc/README.log diff --git a/doc/README.log b/doc/README.log deleted file mode 100644 index a313399fc9..0000000000 --- a/doc/README.log +++ /dev/null @@ -1,283 +0,0 @@ -Logging in U-Boot -================= - -Introduction ------------- - -U-Boot's internal operation involves many different steps and actions. From -setting up the board to displaying a start-up screen to loading an Operating -System, there are many component parts each with many actions. - -Most of the time this internal detail is not useful. Displaying it on the -console would delay booting (U-Boot's primary purpose) and confuse users. - -But for digging into what is happening in a particular area, or for debugging -a problem it is often useful to see what U-Boot is doing in more detail than -is visible from the basic console output. - -U-Boot's logging feature aims to satisfy this goal for both users and -developers. - - -Logging levels --------------- - -There are a number logging levels available, in increasing order of verbosity: - - LOGL_EMERG - Printed before U-Boot halts - LOGL_ALERT - Indicates action must be taken immediate or U-Boot will crash - LOGL_CRIT - Indicates a critical error that will cause boot failure - LOGL_ERR - Indicates an error that may cause boot failure - LOGL_WARNING - Warning about an unexpected condition - LOGL_NOTE - Important information about progress - LOGL_INFO - Information about normal boot progress - LOGL_DEBUG - Debug information (useful for debugging a driver or subsystem) - LOGL_DEBUG_CONTENT - Debug message showing full message content - LOGL_DEBUG_IO - Debug message showing hardware I/O access - - -Logging category ----------------- - -Logging can come from a wide variety of places within U-Boot. Each log message -has a category which is intended to allow messages to be filtered according to -their source. - -The following main categories are defined: - - LOGC_NONE - Unknown category (e.g. a debug() statement) - UCLASS_... - Related to a particular uclass (e.g. UCLASS_USB) - LOGC_ARCH - Related to architecture-specific code - LOGC_BOARD - Related to board-specific code - LOGC_CORE - Related to core driver-model support - LOGC_DT - Related to device tree control - LOGC_EFI - Related to EFI implementation - - -Enabling logging ----------------- - -The following options are used to enable logging at compile time: - - CONFIG_LOG - Enables the logging system - CONFIG_LOG_MAX_LEVEL - Max log level to build (anything higher is compiled - out) - CONFIG_LOG_CONSOLE - Enable writing log records to the console - -If CONFIG_LOG is not set, then no logging will be available. - -The above have SPL and TPL versions also, e.g. CONFIG_SPL_LOG_MAX_LEVEL and -CONFIG_TPL_LOG_MAX_LEVEL. - - -Temporary logging within a single file --------------------------------------- - -Sometimes it is useful to turn on logging just in one file. You can use this: - - #define LOG_DEBUG - -to enable building in of all logging statements in a single file. Put it at -the top of the file, before any #includes. This overrides any log-level setting -in U-Boot, including CONFIG_LOG_DEFAULT_LEVEL, but just for that file. - - -Convenience functions ---------------------- - -A number of convenience functions are available to shorten the code needed -for logging: - - log_err(_fmt...) - log_warning(_fmt...) - log_notice(_fmt...) - log_info(_fmt...) - log_debug(_fmt...) - log_content(_fmt...) - log_io(_fmt...) - -With these the log level is implicit in the name. The category is set by -LOG_CATEGORY, which you can only define once per file, above all #includes: - - #define LOG_CATEGORY LOGC_ALLOC - -or - - #define LOG_CATEGORY UCLASS_SPI - -Remember that all uclasses IDs are log categories too. - - -Log commands ------------- - -The 'log' command provides access to several features: - - level - access the default log level - format - access the console log format - rec - output a log record - test - run tests - -Type 'help log' for details. - - -Using DEBUG ------------ - -U-Boot has traditionally used a #define called DEBUG to enable debugging on a -file-by-file basis. The debug() macro compiles to a printf() statement if -DEBUG is enabled, and an empty statement if not. - -With logging enabled, debug() statements are interpreted as logging output -with a level of LOGL_DEBUG and a category of LOGC_NONE. - -The logging facilities are intended to replace DEBUG, but if DEBUG is defined -at the top of a file, then it takes precedence. This means that debug() -statements will result in output to the console and this output will not be -logged. - - -Logging destinations --------------------- - -If logging information goes nowhere then it serves no purpose. U-Boot provides -several possible determinations for logging information, all of which can be -enabled or disabled independently: - - console - goes to stdout - syslog - broadcast RFC 3164 messages to syslog servers on UDP port 514 - -The syslog driver sends the value of environmental variable 'log_hostname' as -HOSTNAME if available. - -Log format ----------- - -You can control the log format using the 'log format' command. The basic -format is: - - LEVEL.category,file.c:123-func() message - -In the above, file.c:123 is the filename where the log record was generated and -func() is the function name. By default ('log format default') only the -function name and message are displayed on the console. You can control which -fields are present, but not the field order. - - -Filters -------- - -Filters are attached to log drivers to control what those drivers emit. Only -records that pass through the filter make it to the driver. - -Filters can be based on several criteria: - - - maximum log level - - in a set of categories - - in a set of files - -If no filters are attached to a driver then a default filter is used, which -limits output to records with a level less than CONFIG_LOG_MAX_LEVEL. - - -Logging statements ------------------- - -The main logging function is: - - log(category, level, format_string, ...) - -Also debug() and error() will generate log records - these use LOG_CATEGORY -as the category, so you should #define this right at the top of the source -file to ensure the category is correct. - -You can also define CONFIG_LOG_ERROR_RETURN to enable the log_ret() macro. This -can be used whenever your function returns an error value: - - return log_ret(uclass_first_device(UCLASS_MMC, &dev)); - -This will write a log record when an error code is detected (a value < 0). This -can make it easier to trace errors that are generated deep in the call stack. - - -Code size ---------- - -Code size impact depends largely on what is enabled. The following numbers are -generated by 'buildman -S' for snow, which is a Thumb-2 board (all units in -bytes): - -This series: adds bss +20.0 data +4.0 rodata +4.0 text +44.0 -CONFIG_LOG: bss -52.0 data +92.0 rodata -635.0 text +1048.0 -CONFIG_LOG_MAX_LEVEL=7: bss +188.0 data +4.0 rodata +49183.0 text +98124.0 - -The last option turns every debug() statement into a logging call, which -bloats the code hugely. The advantage is that it is then possible to enable -all logging within U-Boot. - - -To Do ------ - -There are lots of useful additions that could be made. None of the below is -implemented! If you do one, please add a test in test/py/tests/test_log.py - -Convenience functions to support setting the category: - - log_arch(level, format_string, ...) - category LOGC_ARCH - log_board(level, format_string, ...) - category LOGC_BOARD - log_core(level, format_string, ...) - category LOGC_CORE - log_dt(level, format_string, ...) - category LOGC_DT - -More logging destinations: - - device - goes to a device (e.g. serial) - buffer - recorded in a memory buffer - -Convert debug() statements in the code to log() statements - -Support making printf() emit log statements a L_INFO level - -Convert error() statements in the code to log() statements - -Figure out what to do with BUG(), BUG_ON() and warn_non_spl() - -Figure out what to do with assert() - -Add a way to browse log records - -Add a way to record log records for browsing using an external tool - -Add commands to add and remove filters - -Add commands to add and remove log devices - -Allow sharing of printf format strings in log records to reduce storage size -for large numbers of log records - -Add a command-line option to sandbox to set the default logging level - -Convert core driver model code to use logging - -Convert uclasses to use logging with the correct category - -Consider making log() calls emit an automatic newline, perhaps with a logn() - function to avoid that - -Passing log records through to linux (e.g. via device tree /chosen) - -Provide a command to access the number of log records generated, and the -number dropped due to them being generated before the log system was ready. - -Add a printf() format string pragma so that log statements are checked properly - -Enhance the log console driver to show level / category / file / line -information - -Add a command to add new log records and delete existing records. - -Provide additional log() functions - e.g. logc() to specify the category - --- -Simon Glass -15-Sep-17