Merge branch '2020-10-27-further-log-enhancements'

- Allow for log message continuation.
- Test fix, build time error checking for new categories

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;
@@ -191,32 +197,33 @@ 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)
 {
 	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)
-		return 0;
+	if (gd->processing_msg)
+		return 1;
 
 	/* 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;
 }
 
@@ -227,6 +234,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;
@@ -242,7 +255,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;
 }
@@ -382,6 +398,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;
 }

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

include/asm-generic/global_data.h

@@ -363,6 +363,26 @@ 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;
+	/**
+	 * @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)
 	/**

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

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
 

test/log/cont_test.c

@@ -0,0 +1,52 @@
+// SPDX-License-Identifier: GPL-2.0+
+/*
+ * Copyright (c) 2020, Heinrich Schuchardt <xypron.glpk@gmx.de>
+ *
+ * Test continuation of log messages.
+ */
+
+#include <common.h>
+#include <console.h>
+#include <test/log.h>
+#include <test/test.h>
+#include <test/suites.h>
+#include <test/ut.h>
+
+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);