diff mbox series

[v2] log: Allow LOG_DEBUG to always enable log output

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

Commit Message

Simon Glass Sept. 27, 2020, 3:55 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.

Signed-off-by: Simon Glass <sjg@chromium.org>
---

Changes in v2:
- Avoid clang-10 warning about converting an enum constant to a boolean

 common/log.c           | 11 ++++++++---
 doc/README.log         | 10 ++++------
 include/log.h          | 17 +++++++++++++----
 test/log/syslog_test.c |  2 +-
 4 files changed, 26 insertions(+), 14 deletions(-)

Comments

Simon Glass Sept. 27, 2020, 3:57 p.m. UTC | #1
+Tom Rini too

On Sun, 27 Sep 2020 at 09:55, Simon Glass <sjg@chromium.org> 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.
>
> Signed-off-by: Simon Glass <sjg@chromium.org>
> ---
>
> Changes in v2:
> - Avoid clang-10 warning about converting an enum constant to a boolean
>
>  common/log.c           | 11 ++++++++---
>  doc/README.log         | 10 ++++------
>  include/log.h          | 17 +++++++++++++----
>  test/log/syslog_test.c |  2 +-
>  4 files changed, 26 insertions(+), 14 deletions(-)
>
> diff --git a/common/log.c b/common/log.c
> index 9a5f100da34..1680a2292a7 100644
> --- a/common/log.c
> +++ b/common/log.c
> @@ -156,16 +156,20 @@ static bool log_has_file(const char *file_list, const char *file)
>  static bool log_passes_filters(struct log_device *ldev, struct log_rec *rec)
>  {
>         struct log_filter *filt;
> +       int level = rec->level & LOGL_LEVEL_MASK;
> +
> +       if (rec->force_debug && level <= LOGL_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)
> +               if (level > gd->default_log_level)
>                         return false;
>                 return true;
>         }
>
>         list_for_each_entry(filt, &ldev->filter_head, sibling_node) {
> -               if (rec->level > filt->max_level)
> +               if (level > filt->max_level)
>                         continue;
>                 if ((filt->flags & LOGFF_HAS_CAT) &&
>                     !log_has_cat(filt->cat_list, rec->cat))
> @@ -219,7 +223,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..554e99ca4ca 100644
> --- a/doc/README.log
> +++ b/doc/README.log
> @@ -77,12 +77,10 @@ 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.
> +to enable building in of all debug 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.
> +All logging statements, up to and including LOGL_DEBUG, will be displayed.
>
>
>  Convenience functions
> diff --git a/include/log.h b/include/log.h
> index 2859ce1f2e7..de56b73a001 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,10 @@ 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), _l | _LOG_DEBUG, __FILE__, \
> +                    __LINE__, __func__, \
>                       pr_fmt(_fmt), ##_args); \
>         })
>  #else
> @@ -279,8 +283,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 +297,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/syslog_test.c b/test/log/syslog_test.c
> index 120a8b2537b..df239d1e8d7 100644
> --- a/test/log/syslog_test.c
> +++ b/test/log/syslog_test.c
> @@ -276,7 +276,7 @@ static int log_test_syslog_nodebug(struct unit_test_state *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");
> +       log_content("testing %s\n", "log_debug");
>         sandbox_eth_set_tx_handler(0, NULL);
>         /* Check that the callback function was not called */
>         ut_assertnonnull(env.expected);
> --
> 2.28.0.681.g6f77f65b4e-goog
>
Tom Rini Oct. 12, 2020, 1:15 a.m. UTC | #2
On Sun, Sep 27, 2020 at 09:55: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.
> 
> Signed-off-by: Simon Glass <sjg@chromium.org>
> ---
> 
> Changes in v2:
> - Avoid clang-10 warning about converting an enum constant to a boolean

So, this is v2 and
https://patchwork.ozlabs.org/project/uboot/patch/20200912171335.3889616-1-sjg@chromium.org/
is also v2, and I started by taking the former.  It looks like that
might be right but please send a follow-up to reconcile anything that
needs it, thanks!
diff mbox series

Patch

diff --git a/common/log.c b/common/log.c
index 9a5f100da34..1680a2292a7 100644
--- a/common/log.c
+++ b/common/log.c
@@ -156,16 +156,20 @@  static bool log_has_file(const char *file_list, const char *file)
 static bool log_passes_filters(struct log_device *ldev, struct log_rec *rec)
 {
 	struct log_filter *filt;
+	int level = rec->level & LOGL_LEVEL_MASK;
+
+	if (rec->force_debug && level <= LOGL_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)
+		if (level > gd->default_log_level)
 			return false;
 		return true;
 	}
 
 	list_for_each_entry(filt, &ldev->filter_head, sibling_node) {
-		if (rec->level > filt->max_level)
+		if (level > filt->max_level)
 			continue;
 		if ((filt->flags & LOGFF_HAS_CAT) &&
 		    !log_has_cat(filt->cat_list, rec->cat))
@@ -219,7 +223,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..554e99ca4ca 100644
--- a/doc/README.log
+++ b/doc/README.log
@@ -77,12 +77,10 @@  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.
+to enable building in of all debug 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.
+All logging statements, up to and including LOGL_DEBUG, will be displayed.
 
 
 Convenience functions
diff --git a/include/log.h b/include/log.h
index 2859ce1f2e7..de56b73a001 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,10 @@  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), _l | _LOG_DEBUG, __FILE__, \
+		     __LINE__, __func__, \
 		      pr_fmt(_fmt), ##_args); \
 	})
 #else
@@ -279,8 +283,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 +297,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/syslog_test.c b/test/log/syslog_test.c
index 120a8b2537b..df239d1e8d7 100644
--- a/test/log/syslog_test.c
+++ b/test/log/syslog_test.c
@@ -276,7 +276,7 @@  static int log_test_syslog_nodebug(struct unit_test_state *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");
+	log_content("testing %s\n", "log_debug");
 	sandbox_eth_set_tx_handler(0, NULL);
 	/* Check that the callback function was not called */
 	ut_assertnonnull(env.expected);