From 17157a2dde88a5cea357c2b88acb328081b67f0d Mon Sep 17 00:00:00 2001 From: Mateusz Majewski Date: Wed, 12 Oct 2022 14:16:33 +0200 Subject: [PATCH] zlogger: ensure the timestamp always increases The kernel guarantees that it won't decrease, but if function is executed in quick repetition it might happen that we get the same value twice in a row. This is unacceptable, since the timestamp is the only thing we rely on in order to sort the messages. Change-Id: I64e0255acede0af44a8510705f469e55cde6ca30 --- kernel/zlogger/zlogger.c | 15 +++++++++++++-- 1 file changed, 13 insertions(+), 2 deletions(-) diff --git a/kernel/zlogger/zlogger.c b/kernel/zlogger/zlogger.c index 09ed375..4290577 100644 --- a/kernel/zlogger/zlogger.c +++ b/kernel/zlogger/zlogger.c @@ -94,6 +94,7 @@ struct zlog_file { char msg[ZLOGGER_MSG_MAX]; char *buffer; size_t buffer_len; + uint64_t last_ts; }; /* --zlogger file channel */ @@ -433,6 +434,7 @@ static ssize_t init_file_zlog_tag_data(struct file *filep) return -ENOMEM; } zlog_file_data->buffer_len = LOG_BUFFER_SIZE; + zlog_file_data->last_ts = 0; filep->private_data = (void *)zlog_file_data; return 0; } @@ -449,7 +451,7 @@ int update_zlog_data_buffer_size(struct zlog_file *zlog_file_data, size_t len) return 0; } -static int _zlog_write(const unsigned char prio, const char *tag, const char *msg) +static int _zlog_write(const unsigned char prio, const char *tag, const char *msg, uint64_t *last_ts) { uint64_t ts = ktime_get_ns(); uint16_t *slt = (uint16_t *)&ts; @@ -478,6 +480,14 @@ static int _zlog_write(const unsigned char prio, const char *tag, const char *ms return -EFAULT; } + /* Ensure that the timestamp is increasing, as opposed to + * merely not decreasing. This is done to make sure that + * logs can be sorted (which can be ambiguous if there are + * multiple valid logs with the same timestamp). */ + if (*last_ts >= ts) + ts = *last_ts + 1; + *last_ts = ts; + tmp.time = ts; tmp.CRC = slt[0] + slt[1] + slt[2] + slt[3]; tmp.len = (uint16_t)entry_size - hd_size; @@ -509,6 +519,7 @@ static ssize_t partition_write_buffer(struct zlog_file *zlog_file_data, size_t l { char *cb = (char *)zlog_file_data->buffer; char *buffer = (char *)zlog_file_data->buffer; + uint64_t *last_ts = &zlog_file_data->last_ts; endl_to_zero(zlog_file_data, len); @@ -519,7 +530,7 @@ static ssize_t partition_write_buffer(struct zlog_file *zlog_file_data, size_t l cb++; continue; } - res = _zlog_write((const unsigned char)zlog_file_data->prio, (const char *)&zlog_file_data->tag, (const char *)cb); + res = _zlog_write((const unsigned char)zlog_file_data->prio, (const char *)&zlog_file_data->tag, (const char *)cb, last_ts); if (res < 0) { pr_err("_zlog_write failed\n"); return -EFAULT; -- 2.34.1