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 <sjg@chromium.org>

diff --git a/common/log.c b/common/log.c
index 9a5f100..ac34f1c 100644 (file)
--- 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 ba83882..a313399 100644 (file)
--- 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 2859ce1..86c8d7b 100644 (file)
--- 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 4c92550..52e2f7b 100644 (file)
--- 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 120a8b2..abcb9ff 100644 (file)
--- a/test/log/syslog_test.c
+++ b/test/log/syslog_test.c
@@ -18,48 +18,11 @@
 #include <test/suites.h>
 #include <test/ut.h>
 #include <asm/eth.h>
+#include <syslog_test.h>
 
 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 (file)
index 0000000..75900f3
--- /dev/null
+++ b/test/log/syslog_test.h
@@ -0,0 +1,50 @@
+/* SPDX-License-Identifier: GPL-2.0+ */
+/*
+ * Copyright (c) 2020, Heinrich Schuchardt <xypron.glpk@gmx.de>
+ *
+ * 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 (file)
index 0000000..7815977
--- /dev/null
+++ b/test/log/syslog_test_ndebug.c
@@ -0,0 +1,55 @@
+// SPDX-License-Identifier: GPL-2.0+
+/*
+ * Copyright (c) 2020, Heinrich Schuchardt <xypron.glpk@gmx.de>
+ *
+ * Logging function tests for CONFIG_LOG_SYSLOG=y.
+ *
+ * Invoke the test with: ./u-boot -d arch/sandbox/dts/test.dtb
+ */
+
+#include <common.h>
+#include <dm/device.h>
+#include <hexdump.h>
+#include <test/log.h>
+#include <test/test.h>
+#include <test/suites.h>
+#include <test/ut.h>
+#include <asm/eth.h>
+#include <syslog_test.h>
+
+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);