[PATCH v4 0/2] log: don't show function by default

[PATCH v4 0/2] log: don't show function by default

[Heinrich Schuchardt]

When replacing printf() by log function calls it is not desirable to output
calling function name. So we should adjust the default log format to show
the message only.

Using the BIT() macro makes the log format related coding more readable.

v4:
	leave an empty line in enum log_fmt before composite values
	rebase on origin/master

Heinrich Schuchardt (2):
  log: don't show function by default
  log: use BIT() instead of 1 <<

 cmd/log.c                 |  4 ++--
 common/Kconfig            | 18 ++++++++++++++++++
 common/log.c              |  2 +-
 common/log_console.c      | 14 +++++++-------
 common/log_syslog.c       | 14 +++++++-------
 include/log.h             | 18 +++++++++++++++++-
 test/log/syslog_test.c    | 20 ++++++++++++++------
 test/py/tests/test_log.py |  2 ++
 8 files changed, 68 insertions(+), 24 deletions(-)

--
2.27.0

[PATCH v4 1/2] log: don't show function by default

[Heinrich Schuchardt]

The name of the function emitting a log message may be of interest for a
developer but is distracting for normal users. See the example below:

    try_load_entry() Booting: Debian

Make the default format for log messages customizable. By default show
only the message text.

Signed-off-by: Heinrich Schuchardt <xypron.glpk@gmx.de>
---
v4:
	leave an empty line in enum log_fmt before composite values
	rebase on origin/master
v3:
	replace #ifdef by IS_ENABLED()
---
 cmd/log.c                 |  4 ++--
 common/Kconfig            | 18 ++++++++++++++++++
 common/log.c              |  2 +-
 include/log.h             | 18 +++++++++++++++++-
 test/log/syslog_test.c    | 20 ++++++++++++++------
 test/py/tests/test_log.py |  2 ++
 6 files changed, 54 insertions(+), 10 deletions(-)

diff --git a/cmd/log.c b/cmd/log.c
index 664f7bd7ac..6b7103550d 100644
--- a/cmd/log.c
+++ b/cmd/log.c
@@ -31,7 +31,7 @@ static int do_log_format(struct cmd_tbl *cmdtp, int flag, int argc,
 		const char *str = argv[1];

 		if (!strcmp(str, "default")) {
-			gd->log_fmt = LOGF_DEFAULT;
+			gd->log_fmt = log_get_default_format();
 		} else if (!strcmp(str, "all")) {
 			gd->log_fmt = LOGF_ALL;
 		} else {
@@ -131,7 +131,7 @@ static char log_help_text[] =
 	"log format <fmt> - set log output format. <fmt> is a string where\n"
 	"\teach letter indicates something that should be displayed:\n"
 	"\tc=category, l=level, F=file, L=line number, f=function, m=msg\n"
-	"\tor 'default', equivalent to 'fm', or 'all' for all\n"
+	"\tor 'default', or 'all' for all\n"
 	"log rec <category> <level> <file> <line> <func> <message> - "
 		"output a log record"
 	;
diff --git a/common/Kconfig b/common/Kconfig
index 2d86dd7e63..efd103b8cb 100644
--- a/common/Kconfig
+++ b/common/Kconfig
@@ -775,6 +775,24 @@ config TPL_LOG_CONSOLE
 	  log message is shown - other details like level, category, file and
 	  line number are omitted.

+config LOGF_FILE
+	bool "Show source file name in log messages by default"
+	help
+	  Show the source file name in log messages by default. This value
+	  can be overridden using the 'log format' command.
+
+config LOGF_LINE
+	bool "Show source line number in log messages by default"
+	help
+	  Show the source line number in log messages by default. This value
+	  can be overridden using the 'log format' command.
+
+config LOGF_FUNC
+	bool "Show function name in log messages by default"
+	help
+	  Show the function name in log messages by default. This value can
+	  be overridden using the 'log format' command.
+
 config LOG_SYSLOG
 	bool "Log output to syslog server"
 	depends on LOG && NET
diff --git a/common/log.c b/common/log.c
index c5b9b489ca..9005b3afb2 100644
--- a/common/log.c
+++ b/common/log.c
@@ -317,7 +317,7 @@ int log_init(void)
 	gd->flags |= GD_FLG_LOG_READY;
 	if (!gd->default_log_level)
 		gd->default_log_level = CONFIG_LOG_DEFAULT_LEVEL;
-	gd->log_fmt = LOGF_DEFAULT;
+	gd->log_fmt = log_get_default_format();

 	return 0;
 }
diff --git a/include/log.h b/include/log.h
index df65398c04..2859ce1f2e 100644
--- a/include/log.h
+++ b/include/log.h
@@ -12,6 +12,7 @@
 #include <stdio.h>
 #include <linker_lists.h>
 #include <dm/uclass-id.h>
+#include <linux/bitops.h>
 #include <linux/list.h>

 struct cmd_tbl;
@@ -411,7 +412,6 @@ enum log_fmt {
 	LOGF_MSG,

 	LOGF_COUNT,
-	LOGF_DEFAULT = (1 << LOGF_FUNC) | (1 << LOGF_MSG),
 	LOGF_ALL = 0x3f,
 };

@@ -460,4 +460,20 @@ static inline int log_init(void)
 }
 #endif

+/**
+ * log_get_default_format() - get default log format
+ *
+ * The default log format is configurable via
+ * CONFIG_LOGF_FILE, CONFIG_LOGF_LINE, CONFIG_LOGF_FUNC.
+ *
+ * Return:	default log format
+ */
+static inline int log_get_default_format(void)
+{
+	return BIT(LOGF_MSG) |
+	       (IS_ENABLED(CONFIG_LOGF_FILE) ? BIT(LOGF_FILE) : 0) |
+	       (IS_ENABLED(CONFIG_LOGF_LINE) ? BIT(LOGF_LINE) : 0) |
+	       (IS_ENABLED(CONFIG_LOGF_FUNC) ? BIT(LOGF_FUNC) : 0);
+}
+
 #endif
diff --git a/test/log/syslog_test.c b/test/log/syslog_test.c
index 26536ebca7..120a8b2537 100644
--- a/test/log/syslog_test.c
+++ b/test/log/syslog_test.c
@@ -21,6 +21,8 @@

 DECLARE_GLOBAL_DATA_PTR;

+#define LOGF_TEST (BIT(LOGF_FUNC) | BIT(LOGF_MSG))
+
 /**
  * struct sb_log_env - private data for sandbox ethernet driver
  *
@@ -102,7 +104,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;

-	gd->log_fmt = LOGF_DEFAULT;
+	gd->log_fmt = LOGF_TEST;
 	gd->default_log_level = LOGL_INFO;
 	env_set("ethact", "eth at 10002000");
 	env_set("log_hostname", "sandbox");
@@ -116,6 +118,7 @@ static int log_test_syslog_err(struct unit_test_state *uts)
 	/* Check that the callback function was called */
 	sandbox_eth_set_tx_handler(0, NULL);
 	gd->default_log_level = old_log_level;
+	gd->log_fmt = log_get_default_format();

 	return 0;
 }
@@ -132,7 +135,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;

-	gd->log_fmt = LOGF_DEFAULT;
+	gd->log_fmt = LOGF_TEST;
 	gd->default_log_level = LOGL_INFO;
 	env_set("ethact", "eth at 10002000");
 	env_set("log_hostname", "sandbox");
@@ -147,6 +150,7 @@ static int log_test_syslog_warning(struct unit_test_state *uts)
 	/* Check that the callback function was called */
 	ut_assertnull(env.expected);
 	gd->default_log_level = old_log_level;
+	gd->log_fmt = log_get_default_format();

 	return 0;
 }
@@ -163,7 +167,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;

-	gd->log_fmt = LOGF_DEFAULT;
+	gd->log_fmt = LOGF_TEST;
 	gd->default_log_level = LOGL_INFO;
 	env_set("ethact", "eth at 10002000");
 	env_set("log_hostname", "sandbox");
@@ -178,6 +182,7 @@ static int log_test_syslog_notice(struct unit_test_state *uts)
 	/* Check that the callback function was called */
 	ut_assertnull(env.expected);
 	gd->default_log_level = old_log_level;
+	gd->log_fmt = log_get_default_format();

 	return 0;
 }
@@ -194,7 +199,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;

-	gd->log_fmt = LOGF_DEFAULT;
+	gd->log_fmt = LOGF_TEST;
 	gd->default_log_level = LOGL_INFO;
 	env_set("ethact", "eth at 10002000");
 	env_set("log_hostname", "sandbox");
@@ -209,6 +214,7 @@ static int log_test_syslog_info(struct unit_test_state *uts)
 	/* Check that the callback function was called */
 	ut_assertnull(env.expected);
 	gd->default_log_level = old_log_level;
+	gd->log_fmt = log_get_default_format();

 	return 0;
 }
@@ -225,7 +231,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;

-	gd->log_fmt = LOGF_DEFAULT;
+	gd->log_fmt = LOGF_TEST;
 	gd->default_log_level = LOGL_DEBUG;
 	env_set("ethact", "eth at 10002000");
 	env_set("log_hostname", "sandbox");
@@ -240,6 +246,7 @@ static int log_test_syslog_debug(struct unit_test_state *uts)
 	/* Check that the callback function was called */
 	ut_assertnull(env.expected);
 	gd->default_log_level = old_log_level;
+	gd->log_fmt = log_get_default_format();

 	return 0;
 }
@@ -259,7 +266,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;

-	gd->log_fmt = LOGF_DEFAULT;
+	gd->log_fmt = LOGF_TEST;
 	gd->default_log_level = LOGL_INFO;
 	env_set("ethact", "eth at 10002000");
 	env_set("log_hostname", "sandbox");
@@ -274,6 +281,7 @@ static int log_test_syslog_nodebug(struct unit_test_state *uts)
 	/* 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;
 }
diff --git a/test/py/tests/test_log.py b/test/py/tests/test_log.py
index 75325fad61..ddc28f19ee 100644
--- a/test/py/tests/test_log.py
+++ b/test/py/tests/test_log.py
@@ -39,6 +39,8 @@ def test_log(u_boot_console):
         Returns:
             iterator containing the lines output from the command
         """
+        output = u_boot_console.run_command('log format fm')
+        assert output == ''
         with cons.log.section('basic'):
            output = u_boot_console.run_command('log test %d' % testnum)
         split = output.replace('\r', '').splitlines()
--
2.27.0

[PATCH v4 2/2] log: use BIT() instead of 1 <<

[Heinrich Schuchardt]

Use the BIT() macro when creating a bitmask for the logging fields.

Signed-off-by: Heinrich Schuchardt <xypron.glpk@gmx.de>
Reviewed-by: Simon Glass <sjg@chromium.org>
---
v4:
	no change
v3:
	new patch
---
 common/log_console.c | 14 +++++++-------
 common/log_syslog.c  | 14 +++++++-------
 2 files changed, 14 insertions(+), 14 deletions(-)

diff --git a/common/log_console.c b/common/log_console.c
index 0b5b7089af..bb3f8464b9 100644
--- a/common/log_console.c
+++ b/common/log_console.c
@@ -25,18 +25,18 @@ static int log_console_emit(struct log_device *ldev, struct log_rec *rec)
 	 *    - function is an identifier and ends with ()
 	 *    - message has a space before it unless it is on its own
 	 */
-	if (fmt & (1 << LOGF_LEVEL))
+	if (fmt & BIT(LOGF_LEVEL))
 		printf("%s.", log_get_level_name(rec->level));
-	if (fmt & (1 << LOGF_CAT))
+	if (fmt & BIT(LOGF_CAT))
 		printf("%s,", log_get_cat_name(rec->cat));
-	if (fmt & (1 << LOGF_FILE))
+	if (fmt & BIT(LOGF_FILE))
 		printf("%s:", rec->file);
-	if (fmt & (1 << LOGF_LINE))
+	if (fmt & BIT(LOGF_LINE))
 		printf("%d-", rec->line);
-	if (fmt & (1 << LOGF_FUNC))
+	if (fmt & BIT(LOGF_FUNC))
 		printf("%s()", rec->func);
-	if (fmt & (1 << LOGF_MSG))
-		printf("%s%s", fmt != (1 << LOGF_MSG) ? " " : "", rec->msg);
+	if (fmt & BIT(LOGF_MSG))
+		printf("%s%s", fmt != BIT(LOGF_MSG) ? " " : "", rec->msg);

 	return 0;
 }
diff --git a/common/log_syslog.c b/common/log_syslog.c
index 698c585fa1..149ff5af31 100644
--- a/common/log_syslog.c
+++ b/common/log_syslog.c
@@ -82,21 +82,21 @@ static int log_syslog_emit(struct log_device *ldev, struct log_rec *rec)
 	if (log_hostname)
 		append(&ptr, msg_end, "%s ", log_hostname);
 	append(&ptr, msg_end, "uboot: ");
-	if (fmt & (1 << LOGF_LEVEL))
+	if (fmt & BIT(LOGF_LEVEL))
 		append(&ptr, msg_end, "%s.",
 		       log_get_level_name(rec->level));
-	if (fmt & (1 << LOGF_CAT))
+	if (fmt & BIT(LOGF_CAT))
 		append(&ptr, msg_end, "%s,",
 		       log_get_cat_name(rec->cat));
-	if (fmt & (1 << LOGF_FILE))
+	if (fmt & BIT(LOGF_FILE))
 		append(&ptr, msg_end, "%s:", rec->file);
-	if (fmt & (1 << LOGF_LINE))
+	if (fmt & BIT(LOGF_LINE))
 		append(&ptr, msg_end, "%d-", rec->line);
-	if (fmt & (1 << LOGF_FUNC))
+	if (fmt & BIT(LOGF_FUNC))
 		append(&ptr, msg_end, "%s()", rec->func);
-	if (fmt & (1 << LOGF_MSG))
+	if (fmt & BIT(LOGF_MSG))
 		append(&ptr, msg_end, "%s%s",
-		       fmt != (1 << LOGF_MSG) ? " " : "", rec->msg);
+		       fmt != BIT(LOGF_MSG) ? " " : "", rec->msg);
 	/* Consider trailing 0x00 */
 	ptr++;

--
2.27.0

[PATCH v4 1/2] log: don't show function by default

[Simon Glass]

On Wed, 17 Jun 2020 at 13:52, Heinrich Schuchardt <xypron.glpk@gmx.de> wrote:
>
> The name of the function emitting a log message may be of interest for a
> developer but is distracting for normal users. See the example below:
>
>     try_load_entry() Booting: Debian
>
> Make the default format for log messages customizable. By default show
> only the message text.
>
> Signed-off-by: Heinrich Schuchardt <xypron.glpk@gmx.de>
> ---
> v4:
>         leave an empty line in enum log_fmt before composite values
>         rebase on origin/master
> v3:
>         replace #ifdef by IS_ENABLED()
> ---
>  cmd/log.c                 |  4 ++--
>  common/Kconfig            | 18 ++++++++++++++++++
>  common/log.c              |  2 +-
>  include/log.h             | 18 +++++++++++++++++-
>  test/log/syslog_test.c    | 20 ++++++++++++++------
>  test/py/tests/test_log.py |  2 ++
>  6 files changed, 54 insertions(+), 10 deletions(-)
>

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

[PATCH v4 2/2] log: use BIT() instead of 1 <<

[Simon Glass]

Use the BIT() macro when creating a bitmask for the logging fields.

Signed-off-by: Heinrich Schuchardt <xypron.glpk@gmx.de>
Reviewed-by: Simon Glass <sjg@chromium.org>
---
v4:
	no change
v3:
	new patch
---
 common/log_console.c | 14 +++++++-------
 common/log_syslog.c  | 14 +++++++-------
 2 files changed, 14 insertions(+), 14 deletions(-)

Applied to u-boot-dm/next, thanks!

[PATCH v4 1/2] log: don't show function by default

[Simon Glass]

On Wed, 17 Jun 2020 at 13:52, Heinrich Schuchardt <xypron.glpk@gmx.de> wrote:
>
> The name of the function emitting a log message may be of interest for a
> developer but is distracting for normal users. See the example below:
>
>     try_load_entry() Booting: Debian
>
> Make the default format for log messages customizable. By default show
> only the message text.
>
> Signed-off-by: Heinrich Schuchardt <xypron.glpk@gmx.de>
> ---
> v4:
>         leave an empty line in enum log_fmt before composite values
>         rebase on origin/master
> v3:
>         replace #ifdef by IS_ENABLED()
> ---
>  cmd/log.c                 |  4 ++--
>  common/Kconfig            | 18 ++++++++++++++++++
>  common/log.c              |  2 +-
>  include/log.h             | 18 +++++++++++++++++-
>  test/log/syslog_test.c    | 20 ++++++++++++++------
>  test/py/tests/test_log.py |  2 ++
>  6 files changed, 54 insertions(+), 10 deletions(-)
>

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

Applied to u-boot-dm/next, thanks!