log: Handle line continuation

When multiple log() calls are used which don't end in newline, the
log prefix is prepended multiple times in the same line. This makes the
output look strange.

Fix this by detecting when the previous log record did not end in newline.
In that case, setting a flag.

Drop the unused BUFFSIZE in the test while we are here.

As an example implementation, update log_console to check the flag and
produce the expected output.

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

diff --git a/common/log.c b/common/log.c
index f87e33a..ea407c6 100644 (file)
--- a/common/log.c
+++ b/common/log.c
@@ -218,8 +218,11 @@ static int log_dispatch(struct log_rec *rec, const char *fmt, va_list args)
                if ((ldev->flags & LOGDF_ENABLE) &&
                    log_passes_filters(ldev, rec)) {
                        if (!rec->msg) {
-                               vsnprintf(buf, sizeof(buf), fmt, args);
+                               int len;
+
+                               len = vsnprintf(buf, sizeof(buf), fmt, args);
                                rec->msg = buf;
+                               gd->log_cont = len && buf[len - 1] != '\n';
                        }
                        ldev->drv->emit(ldev, rec);
                }
@@ -248,6 +251,8 @@ int _log(enum log_category_t cat, enum log_level_t level, const char *file,
        rec.flags = 0;
        if (level & LOGL_FORCE_DEBUG)
                rec.flags |= LOGRECF_FORCE_DEBUG;
+       if (gd->log_cont)
+               rec.flags |= LOGRECF_CONT;
        rec.file = file;
        rec.line = line;
        rec.func = func;

diff --git a/common/log_console.c b/common/log_console.c
index 6abb13c..3f61774 100644 (file)
--- a/common/log_console.c
+++ b/common/log_console.c
@@ -15,6 +15,7 @@ DECLARE_GLOBAL_DATA_PTR;
 static int log_console_emit(struct log_device *ldev, struct log_rec *rec)
 {
        int fmt = gd->log_fmt;
+       bool add_space = false;
 
        /*
         * The output format is designed to give someone a fighting chance of
@@ -26,18 +27,21 @@ 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 & BIT(LOGF_LEVEL))
-               printf("%s.", log_get_level_name(rec->level));
-       if (fmt & BIT(LOGF_CAT))
-               printf("%s,", log_get_cat_name(rec->cat));
-       if (fmt & BIT(LOGF_FILE))
-               printf("%s:", rec->file);
-       if (fmt & BIT(LOGF_LINE))
-               printf("%d-", rec->line);
-       if (fmt & BIT(LOGF_FUNC))
-               printf("%s()", rec->func);
+       if (!(rec->flags & LOGRECF_CONT) && fmt != BIT(LOGF_MSG)) {
+               add_space = true;
+               if (fmt & BIT(LOGF_LEVEL))
+                       printf("%s.", log_get_level_name(rec->level));
+               if (fmt & BIT(LOGF_CAT))
+                       printf("%s,", log_get_cat_name(rec->cat));
+               if (fmt & BIT(LOGF_FILE))
+                       printf("%s:", rec->file);
+               if (fmt & BIT(LOGF_LINE))
+                       printf("%d-", rec->line);
+               if (fmt & BIT(LOGF_FUNC))
+                       printf("%s()", rec->func);
+       }
        if (fmt & BIT(LOGF_MSG))
-               printf("%s%s", fmt != BIT(LOGF_MSG) ? " " : "", rec->msg);
+               printf("%s%s", add_space ? " " : "", rec->msg);
 
        return 0;
 }

diff --git a/doc/develop/logging.rst b/doc/develop/logging.rst
index 60c18c5..622ad6a 100644 (file)
--- a/doc/develop/logging.rst
+++ b/doc/develop/logging.rst
@@ -96,6 +96,22 @@ Also debug() and error() will generate log records  - these use LOG_CATEGORY
 as the category, so you should #define this right at the top of the source
 file to ensure the category is correct.
 
+Generally each log format_string ends with a newline. If it does not, then the
+next log statement will have the LOGRECF_CONT flag set. This can be used to
+continue the statement on the same line as the previous one without emitting
+new header information (such as category/level). This behaviour is implemented
+with log_console. Here is an example that prints a list all on one line with
+the tags at the start:
+
+.. code-block:: c
+
+   log_debug("Here is a list:");
+   for (i = 0; i < count; i++)
+      log_debug(" item %d", i);
+   log_debug("\n");
+
+Also see the special category LOGL_CONT and level LOGC_CONT.
+
 You can also define CONFIG_LOG_ERROR_RETURN to enable the log_ret() macro. This
 can be used whenever your function returns an error value:
 

diff --git a/include/asm-generic/global_data.h b/include/asm-generic/global_data.h
index b6a9991..c24f5e0 100644 (file)
--- a/include/asm-generic/global_data.h
+++ b/include/asm-generic/global_data.h
@@ -410,6 +410,12 @@ struct global_data {
         * This value is used as logging level for continuation messages.
         */
        int logl_prev;
+       /**
+        * @log_cont: Previous log line did not finished wtih \n
+        *
+        * This allows for chained log messages on the same line
+        */
+       bool log_cont;
 #endif
 #if CONFIG_IS_ENABLED(BLOBLIST)
        /**

diff --git a/include/log.h b/include/log.h
index da053b0..c0453d2 100644 (file)
--- a/include/log.h
+++ b/include/log.h
@@ -326,6 +326,8 @@ void __assert_fail(const char *assertion, const char *file, unsigned int line,
 enum log_rec_flags {
        /** @LOGRECF_FORCE_DEBUG: Force output of debug record */
        LOGRECF_FORCE_DEBUG     = BIT(0),
+       /** @LOGRECF_CONT: Continuation of previous log record */
+       LOGRECF_CONT            = BIT(1),
 };
 
 /**

diff --git a/test/log/cont_test.c b/test/log/cont_test.c
index 16379a7..de7b7f0 100644 (file)
--- a/test/log/cont_test.c
+++ b/test/log/cont_test.c
@@ -15,8 +15,6 @@
 
 DECLARE_GLOBAL_DATA_PTR;
 
-#define BUFFSIZE 64
-
 static int log_test_cont(struct unit_test_state *uts)
 {
        int log_fmt;
@@ -29,12 +27,13 @@ static int log_test_cont(struct unit_test_state *uts)
        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_ARCH, LOGL_ERR, "ea%d\n", 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_line(uts, "ERR.arch, ea1"));
+       ut_assertok(ut_check_console_line(uts, "ERR.arch, cc2"));
        ut_assertok(ut_check_console_end(uts));
 
        /* Write a third message which is not a continuation */
@@ -48,6 +47,18 @@ static int log_test_cont(struct unit_test_state *uts)
        ut_assertok(ut_check_console_line(uts, "INFO.efi, ie3"));
        ut_assertok(ut_check_console_end(uts));
 
+       /* Write two messages without a newline between them */
+       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 cc2"));
+       ut_assertok(ut_check_console_end(uts));
+
        return 0;
 }
 LOG_TEST(log_test_cont);