log: enforce single logical messages only

For all but the simplest loggers, the current approach of "this is a
continuation of the previous message" doesn't work well. The caller
cannot know whether the *current* message is complete until it receives
the next message - but that message may never come.

Drop this approach, if we need to compile multiple messages into one,
we can handle this internally and then pass it all as one message to the
caller.
This commit is contained in:
Peter Hutterer 2022-08-02 16:34:10 +10:00
parent 2858b29f1d
commit 876d722356
5 changed files with 30 additions and 68 deletions

View file

@ -36,8 +36,7 @@ static void
ei_default_log_handler(struct ei *ei,
enum ei_log_priority priority,
const char *file, int lineno, const char *func,
const char *message,
bool is_continuation)
const char *message)
{
struct lut {
const char *color;
@ -62,25 +61,20 @@ ei_default_log_handler(struct ei *ei,
}
time_t now = time(NULL);
char timestamp[64];
if (is_continuation) {
fprintf(stderr, "%s", message);
if (last_time != now) {
struct tm *tm = localtime(&now);
strftime(timestamp, sizeof(timestamp), "%T", tm);
} else {
char timestamp[64];
if (last_time != now) {
struct tm *tm = localtime(&now);
strftime(timestamp, sizeof(timestamp), "%T", tm);
} else {
xsnprintf(timestamp, sizeof(timestamp), "...");
}
size_t idx = priority/10;
assert(idx < ARRAY_LENGTH(lut));
fprintf(stderr, " %8s | %s%4s%s | %s", timestamp,
lut[idx].color, lut[idx].prefix, reset_code, message);
xsnprintf(timestamp, sizeof(timestamp), "...");
}
size_t idx = priority/10;
assert(idx < ARRAY_LENGTH(lut));
fprintf(stderr, " %8s | %s%4s%s | %s", timestamp,
lut[idx].color, lut[idx].prefix, reset_code, message);
last_time = now;
}
@ -135,7 +129,7 @@ ei_log_msg_va(struct ei *ei,
return;
_cleanup_free_ char *message = xvasprintf(format, ap);
ei->log.handler(ei, priority, file, lineno, func, message, false);
ei->log.handler(ei, priority, file, lineno, func, message);
}
#ifdef _enable_tests_
@ -144,21 +138,18 @@ ei_log_msg_va(struct ei *ei,
struct log_handler_check {
enum ei_log_priority min_priority;
const char *expected_message;
bool is_continuation;
};
static void
test_loghandler(struct ei *ei,
enum ei_log_priority priority,
const char *file, int lineno, const char *func,
const char *message,
bool is_continuation)
const char *message)
{
struct log_handler_check *check = ei_get_user_data(ei);
munit_assert_int(priority, >=, check->min_priority);
munit_assert_string_equal(message, check->expected_message);
munit_assert(is_continuation == check->is_continuation);
}
MUNIT_TEST(test_log_handler)
@ -173,7 +164,6 @@ MUNIT_TEST(test_log_handler)
check.min_priority = EI_LOG_PRIORITY_INFO; /* default */
check.expected_message = "info message";
check.is_continuation = false,
log_debug(ei, "default is below this level");
log_info(ei, "info message");

View file

@ -423,14 +423,11 @@ enum ei_log_priority {
* @param lineno The line number in @a file where this log message was triggered
* @param func The function name where this log message was triggered
* @param message The log message as a null-terminated string
* @param is_continuation The message is a continuation of the previous
* message. The caller should skip any per-line-based prefixes.
*/
typedef void (*ei_log_handler)(struct ei *ei,
enum ei_log_priority priority,
const char *file, int lineno, const char *func,
const char *message,
bool is_continuation);
const char *message);
/**
* Change the log handler for this context. If the log handler is NULL, the
* built-in default log function is used.

View file

@ -36,8 +36,7 @@ static void
eis_default_log_handler(struct eis *eis,
enum eis_log_priority priority,
const char *file, int lineno, const char *func,
const char *message,
bool is_continuation)
const char *message)
{
struct lut {
const char *color;
@ -62,25 +61,20 @@ eis_default_log_handler(struct eis *eis,
}
time_t now = time(NULL);
char timestamp[64];
if (is_continuation) {
fprintf(stderr, "%s", message);
if (last_time != now) {
struct tm *tm = localtime(&now);
strftime(timestamp, sizeof(timestamp), "%T", tm);
} else {
char timestamp[64];
if (last_time != now) {
struct tm *tm = localtime(&now);
strftime(timestamp, sizeof(timestamp), "%T", tm);
} else {
xsnprintf(timestamp, sizeof(timestamp), "...");
}
size_t idx = priority/10;
assert(idx < ARRAY_LENGTH(lut));
fprintf(stderr, " EIS: %8s | %s%4s%s | %s", timestamp,
lut[idx].color, lut[idx].prefix, reset_code, message);
xsnprintf(timestamp, sizeof(timestamp), "...");
}
size_t idx = priority/10;
assert(idx < ARRAY_LENGTH(lut));
fprintf(stderr, " EIS: %8s | %s%4s%s | %s", timestamp,
lut[idx].color, lut[idx].prefix, reset_code, message);
last_time = now;
}
@ -135,7 +129,7 @@ eis_log_msg_va(struct eis *eis,
return;
_cleanup_free_ char *message = xvasprintf(format, ap);
eis->log.handler(eis, priority, file, lineno, func, message, false);
eis->log.handler(eis, priority, file, lineno, func, message);
}
#ifdef _enable_tests_
@ -144,21 +138,18 @@ eis_log_msg_va(struct eis *eis,
struct log_handler_check {
enum eis_log_priority min_priority;
const char *expected_message;
bool is_continuation;
};
static void
test_loghandler(struct eis *eis,
enum eis_log_priority priority,
const char *file, int lineno, const char *func,
const char *message,
bool is_continuation)
const char *message)
{
struct log_handler_check *check = eis_get_user_data(eis);
munit_assert_int(priority, >=, check->min_priority);
munit_assert_string_equal(message, check->expected_message);
munit_assert(is_continuation == check->is_continuation);
}
MUNIT_TEST(test_log_handler)
@ -173,7 +164,6 @@ MUNIT_TEST(test_log_handler)
check.min_priority = EIS_LOG_PRIORITY_INFO; /* default */
check.expected_message = "info message";
check.is_continuation = false,
log_debug(eis, "default is below this level");
log_info(eis, "info message");

View file

@ -294,14 +294,11 @@ enum eis_log_priority {
* @param lineno The line number in @a file where this log message was triggered
* @param func The function name where this log message was triggered
* @param message The log message as a null-terminated string
* @param is_continuation The message is a continuation of the previous
* message. The caller should skip any per-line-based prefixes.
*/
typedef void (*eis_log_handler)(struct eis *eis,
enum eis_log_priority priority,
const char *file, int lineno, const char *func,
const char *message,
bool is_continuation);
const char *message);
/**
* Change the log handler for this context. If the log handler is NULL, the
* built-in default log function is used.

View file

@ -251,19 +251,13 @@ static void
peck_ei_log_handler(struct ei *ei,
enum ei_log_priority priority,
const char *file, int lineno, const char *func,
const char *message,
bool is_continuation)
const char *message)
{
bool use_color = true;
run_only_once {
use_color = isatty(STDERR_FILENO);
}
if (is_continuation) {
fprintf(stderr, "%s", message);
return;
}
const char *prefix = NULL;
switch (priority) {
case EI_LOG_PRIORITY_ERROR: prefix = "ERR"; break;
@ -284,19 +278,13 @@ static void
peck_eis_log_handler(struct eis *eis,
enum eis_log_priority priority,
const char *file, int lineno, const char *func,
const char *message,
bool is_continuation)
const char *message)
{
bool use_color = true;
run_only_once {
use_color = isatty(STDERR_FILENO);
}
if (is_continuation) {
fprintf(stderr, "%s", message);
return;
}
const char *prefix = NULL;
switch (priority) {
case EIS_LOG_PRIORITY_ERROR: prefix = "ERR"; break;