diff mbox series

[v2,1/2] log: Allow LOG_DEBUG to always enable log output

Message ID 20200912171335.3889616-1-sjg@chromium.org
State Accepted
Delegated to: Tom Rini
Headers show
Series [v2,1/2] log: Allow LOG_DEBUG to always enable log output | expand

Commit Message

Simon Glass Sept. 12, 2020, 5:13 p.m. UTC
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>
---

Changes in v2:
- Move log_test_syslog_nodebug() into its own file
- Add casts for the enum to keep clang happy

 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

Comments

Tom Rini Oct. 12, 2020, 1:14 a.m. UTC | #1
On Sat, Sep 12, 2020 at 11:13:34AM -0600, Simon Glass wrote:

> 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>

Applied to u-boot/master, thanks!
diff mbox series

Patch

diff --git a/common/log.c b/common/log.c
index 734d26de4af..f44f15743ff 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)
@@ -208,7 +211,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 ba838824a99..a313399fc93 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 2859ce1f2e7..86c8d7be09d 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 4c92550f6e3..52e2f7b41c3 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 120a8b2537b..abcb9ffd28b 100644
--- 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
index 00000000000..75900f3aad3
--- /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
index 00000000000..7815977ea27
--- /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);