leandrof/u-boot
1
0
Fork 0
Code Issues Pull Requests Packages Projects Releases Wiki Activity

log: Handle line continuation

Browse Source 
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>
This commit is contained in:
Simon Glass 2021-01-20 20:10:53 -07:00 committed by Tom Rini
parent 79d5983b61
commit 9ad7a6c25c
6 changed files with 60 additions and 16 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

7
common/log.c
View File

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

6
common/log_console.c
View File

@ -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,6 +27,8 @@ 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 (!(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))
@ -36,8 +39,9 @@ static int log_console_emit(struct log_device *ldev, struct log_rec *rec)
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;
}

16
doc/develop/logging.rst
View File

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

6
include/asm-generic/global_data.h
View File

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

2
include/log.h
View File

@ -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),
};
/**

19
test/log/cont_test.c
View File

@ -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);