From 993a06b6144d54ae2ad83cc25c18acb9d1720ad0 Mon Sep 17 00:00:00 2001 From: Heinrich Schuchardt Date: Sat, 17 Oct 2020 14:31:57 +0200 Subject: [PATCH 1/4] log: move processing_msg to global data Replace the static variable processing_msg by a field in the global data. Make the field bool at it can only be true or false. Signed-off-by: Heinrich Schuchardt Reviewed-by: Simon Glass --- common/log.c | 7 +++---- include/asm-generic/global_data.h | 8 ++++++++ 2 files changed, 11 insertions(+), 4 deletions(-) diff --git a/common/log.c b/common/log.c index b7a6ebe298..6a59f2ebe5 100644 --- a/common/log.c +++ b/common/log.c @@ -199,24 +199,23 @@ static bool log_passes_filters(struct log_device *ldev, struct log_rec *rec) static int log_dispatch(struct log_rec *rec) { struct log_device *ldev; - static int processing_msg; /* * When a log driver writes messages (e.g. via the network stack) this * may result in further generated messages. We cannot process them here * as this might result in infinite recursion. */ - if (processing_msg) + if (gd->processing_msg) return 0; /* Emit message */ - processing_msg = 1; + gd->processing_msg = true; list_for_each_entry(ldev, &gd->log_head, sibling_node) { if ((ldev->flags & LOGDF_ENABLE) && log_passes_filters(ldev, rec)) ldev->drv->emit(ldev, rec); } - processing_msg = 0; + gd->processing_msg = false; return 0; } diff --git a/include/asm-generic/global_data.h b/include/asm-generic/global_data.h index ebb740d34f..db83f59ceb 100644 --- a/include/asm-generic/global_data.h +++ b/include/asm-generic/global_data.h @@ -363,6 +363,14 @@ struct global_data { * &enum log_fmt defines the bits of the bit mask. */ int log_fmt; + + /** + * @processing_msg: a log message is being processed + * + * This flag is used to suppress the creation of additional messages + * while another message is being processed. + */ + bool processing_msg; #endif #if CONFIG_IS_ENABLED(BLOBLIST) /** From d094a0734cee439fc8483118694079c85b1cc3db Mon Sep 17 00:00:00 2001 From: Heinrich Schuchardt Date: Sat, 17 Oct 2020 14:31:58 +0200 Subject: [PATCH 2/4] log: allow for message continuation Some drivers use macro pr_cont() for continuing a message sent via printk. Hence if we want to convert printk messaging to using the logging system, we must support continuation of log messages too. As pr_cont() does not provide a message level we need a means of remembering the last log level. With the patch a pseudo log level LOGL_CONT as well as a pseudo log category LOGC_CONT are introduced. Using these results in the application of the same log level and category as in the previous log message. Signed-off-by: Heinrich Schuchardt Reviewed-by: Simon Glass --- common/log.c | 23 ++++++++++++++++++----- doc/develop/logging.rst | 6 ++++++ include/asm-generic/global_data.h | 12 ++++++++++++ include/log.h | 2 ++ 4 files changed, 38 insertions(+), 5 deletions(-) diff --git a/common/log.c b/common/log.c index 6a59f2ebe5..d830883825 100644 --- a/common/log.c +++ b/common/log.c @@ -191,10 +191,12 @@ static bool log_passes_filters(struct log_device *ldev, struct log_rec *rec) * log_dispatch() - Send a log record to all log devices for processing * * The log record is sent to each log device in turn, skipping those which have - * filters which block the record + * filters which block the record. * - * @rec: Log record to dispatch - * @return 0 (meaning success) + * All log messages created while processing log record @rec are ignored. + * + * @rec: log record to dispatch + * Return: 0 msg sent, 1 msg not sent while already dispatching another msg */ static int log_dispatch(struct log_rec *rec) { @@ -206,7 +208,7 @@ static int log_dispatch(struct log_rec *rec) * as this might result in infinite recursion. */ if (gd->processing_msg) - return 0; + return 1; /* Emit message */ gd->processing_msg = true; @@ -226,6 +228,12 @@ int _log(enum log_category_t cat, enum log_level_t level, const char *file, struct log_rec rec; va_list args; + /* Check for message continuation */ + if (cat == LOGC_CONT) + cat = gd->logc_prev; + if (level == LOGL_CONT) + level = gd->logl_prev; + rec.cat = cat; rec.level = level & LOGL_LEVEL_MASK; rec.force_debug = level & LOGL_FORCE_DEBUG; @@ -241,7 +249,10 @@ int _log(enum log_category_t cat, enum log_level_t level, const char *file, gd->log_drop_count++; return -ENOSYS; } - log_dispatch(&rec); + if (!log_dispatch(&rec)) { + gd->logc_prev = cat; + gd->logl_prev = level; + } return 0; } @@ -381,6 +392,8 @@ int log_init(void) if (!gd->default_log_level) gd->default_log_level = CONFIG_LOG_DEFAULT_LEVEL; gd->log_fmt = log_get_default_format(); + gd->logc_prev = LOGC_NONE; + gd->logl_prev = LOGL_INFO; return 0; } diff --git a/doc/develop/logging.rst b/doc/develop/logging.rst index 28340a4aac..528280c3e8 100644 --- a/doc/develop/logging.rst +++ b/doc/develop/logging.rst @@ -38,6 +38,9 @@ There are a number logging levels available, in increasing order of verbosity: * LOGL_DEBUG_CONTENT - Debug message showing full message content * LOGL_DEBUG_IO - Debug message showing hardware I/O access +To continue a log message in a separate call of function log() use + +* LOGL_CONT - Use same log level as in previous call Logging category ---------------- @@ -56,6 +59,9 @@ The following main categories are defined: * LOGC_DT - Related to device tree control * LOGC_EFI - Related to EFI implementation +To continue a log message in a separate call of function log() use + +* LOGC_CONT - Use same category as in previous call Enabling logging ---------------- diff --git a/include/asm-generic/global_data.h b/include/asm-generic/global_data.h index db83f59ceb..0157af1aa4 100644 --- a/include/asm-generic/global_data.h +++ b/include/asm-generic/global_data.h @@ -371,6 +371,18 @@ struct global_data { * while another message is being processed. */ bool processing_msg; + /** + * @logc_prev: logging category of previous message + * + * This value is used as logging category for continuation messages. + */ + int logc_prev; + /** + * @logl_pref: logging level of the previous message + * + * This value is used as logging level for continuation messages. + */ + int logl_prev; #endif #if CONFIG_IS_ENABLED(BLOBLIST) /** diff --git a/include/log.h b/include/log.h index 6de5e611c7..58787a3532 100644 --- a/include/log.h +++ b/include/log.h @@ -38,6 +38,7 @@ enum log_level_t { LOGL_FIRST = LOGL_EMERG, LOGL_MAX = LOGL_DEBUG_IO, + LOGL_CONT = -1, /* Use same log level as in previous call */ }; /** @@ -65,6 +66,7 @@ enum log_category_t { LOGC_COUNT, /* Number of log categories */ LOGC_END, /* Sentinel value for a list of log categories */ + LOGC_CONT = -1, /* Use same category as in previous call */ }; /* Helper to cast a uclass ID to a log category */ From 920157678b863bc34b655212a4bc0d29f84b4a80 Mon Sep 17 00:00:00 2001 From: Heinrich Schuchardt Date: Sat, 17 Oct 2020 14:31:59 +0200 Subject: [PATCH 3/4] test: log: test message continuation Provide a unit test checking that a continuation message will use the same log level and log category as the previous message. Signed-off-by: Heinrich Schuchardt Reviewed-by: Simon Glass --- test/log/Makefile | 4 +++- test/log/cont_test.c | 52 ++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 55 insertions(+), 1 deletion(-) create mode 100644 test/log/cont_test.c diff --git a/test/log/Makefile b/test/log/Makefile index 52e2f7b41c..fdf529582d 100644 --- a/test/log/Makefile +++ b/test/log/Makefile @@ -13,7 +13,9 @@ obj-$(CONFIG_LOG_SYSLOG) += syslog_test.o obj-$(CONFIG_LOG_SYSLOG) += syslog_test_ndebug.o endif -ifndef CONFIG_LOG +ifdef CONFIG_LOG +obj-$(CONFIG_CONSOLE_RECORD) += cont_test.o +else obj-$(CONFIG_CONSOLE_RECORD) += nolog_test.o endif diff --git a/test/log/cont_test.c b/test/log/cont_test.c new file mode 100644 index 0000000000..68ca1d262c --- /dev/null +++ b/test/log/cont_test.c @@ -0,0 +1,52 @@ +// SPDX-License-Identifier: GPL-2.0+ +/* + * Copyright (c) 2020, Heinrich Schuchardt + * + * Test continuation of log messages. + */ + +#include +#include +#include +#include +#include +#include + +DECLARE_GLOBAL_DATA_PTR; + +#define BUFFSIZE 64 + +static int log_test_cont(struct unit_test_state *uts) +{ + int log_fmt; + int log_level; + + log_fmt = gd->log_fmt; + log_level = gd->default_log_level; + + /* Write two messages, the second continuing the first */ + gd->log_fmt = (1 << LOGF_CAT) | (1 << LOGF_LEVEL) | (1 << LOGF_MSG); + gd->default_log_level = LOGL_INFO; + console_record_reset_enable(); + log(LOGC_ARCH, LOGL_ERR, "ea%d ", 1); + log(LOGC_CONT, LOGL_CONT, "cc%d\n", 2); + gd->default_log_level = log_level; + gd->log_fmt = log_fmt; + gd->flags &= ~GD_FLG_RECORD; + ut_assertok(ut_check_console_line(uts, "ERR.arch, ea1 ERR.arch, cc2")); + ut_assertok(ut_check_console_end(uts)); + + /* Write a third message which is not a continuation */ + gd->log_fmt = (1 << LOGF_CAT) | (1 << LOGF_LEVEL) | (1 << LOGF_MSG); + gd->default_log_level = LOGL_INFO; + console_record_reset_enable(); + log(LOGC_EFI, LOGL_INFO, "ie%d\n", 3); + gd->default_log_level = log_level; + gd->log_fmt = log_fmt; + gd->flags &= ~GD_FLG_RECORD; + ut_assertok(ut_check_console_line(uts, "INFO.efi, ie3")); + ut_assertok(ut_check_console_end(uts)); + + return 0; +} +LOG_TEST(log_test_cont); From 2a0cbf3bca372dcbc79048d475c817d4e462069e Mon Sep 17 00:00:00 2001 From: Heinrich Schuchardt Date: Fri, 23 Oct 2020 13:00:01 +0200 Subject: [PATCH 4/4] log: correct and check array size of log categories The log command has led to NULL dereferences if an unknown category name name was used due to missing entries in the list of category names. Add compile time checks for the array sizes of log_cat_name and log_lvl_name to avoid future mishaps. Signed-off-by: Heinrich Schuchardt Reviewed-by: Simon Glass --- common/log.c | 10 ++++++++-- 1 file changed, 8 insertions(+), 2 deletions(-) diff --git a/common/log.c b/common/log.c index d830883825..9f98e9aff8 100644 --- a/common/log.c +++ b/common/log.c @@ -13,7 +13,7 @@ DECLARE_GLOBAL_DATA_PTR; -static const char *log_cat_name[LOGC_COUNT - LOGC_NONE] = { +static const char *log_cat_name[] = { "none", "arch", "board", @@ -28,7 +28,10 @@ static const char *log_cat_name[LOGC_COUNT - LOGC_NONE] = { "acpi", }; -static const char *log_level_name[LOGL_COUNT] = { +_Static_assert(ARRAY_SIZE(log_cat_name) == LOGC_COUNT - LOGC_NONE, + "log_cat_name size"); + +static const char *log_level_name[] = { "EMERG", "ALERT", "CRIT", @@ -41,6 +44,9 @@ static const char *log_level_name[LOGL_COUNT] = { "IO", }; +_Static_assert(ARRAY_SIZE(log_level_name) == LOGL_COUNT, "log_level_name size"); + +/* All error responses MUST begin with '<' */ const char *log_get_cat_name(enum log_category_t cat) { const char *name;