[RFC PATCH v1 24/25] printk: implement kmsg_dump

From: John Ogness
Date: Tue Feb 12 2019 - 09:31:29 EST


Since printk messages are now logged to a new ring buffer, update
the kmsg_dump functions to pull the messages from there.

Signed-off-by: John Ogness <john.ogness@xxxxxxxxxxxxx>
---
include/linux/kmsg_dump.h | 6 +-
kernel/printk/printk.c | 258 ++++++++++++++++++++++++----------------------
2 files changed, 139 insertions(+), 125 deletions(-)

diff --git a/include/linux/kmsg_dump.h b/include/linux/kmsg_dump.h
index 2e7a1e032c71..ede5066663b9 100644
--- a/include/linux/kmsg_dump.h
+++ b/include/linux/kmsg_dump.h
@@ -46,10 +46,8 @@ struct kmsg_dumper {
bool registered;

/* private state of the kmsg iterator */
- u32 cur_idx;
- u32 next_idx;
- u64 cur_seq;
- u64 next_seq;
+ u64 line_seq;
+ u64 buffer_end_seq;
};

#ifdef CONFIG_PRINTK
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 241d142a2755..6d5bb7f5f584 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -397,13 +397,13 @@ static size_t syslog_partial;
static bool syslog_time;

/* index and sequence number of the first record stored in the buffer */
-static u64 log_first_seq;
static u32 log_first_idx;

/* index and sequence number of the next record to store in the buffer */
-static u64 log_next_seq;
static u32 log_next_idx;

+static DEFINE_MUTEX(kmsg_dump_lock);
+
/* the next printk record to read after the last 'clear' command */
static u64 clear_seq;
static u32 clear_idx;
@@ -446,38 +446,6 @@ static char *log_dict(const struct printk_log *msg)
return (char *)msg + sizeof(struct printk_log) + msg->text_len;
}

-/* get record by index; idx must point to valid msg */
-static struct printk_log *log_from_idx(u32 idx)
-{
- struct printk_log *msg = (struct printk_log *)(log_buf + idx);
-
- /*
- * A length == 0 record is the end of buffer marker. Wrap around and
- * read the message at the start of the buffer.
- */
- if (!msg->len)
- return (struct printk_log *)log_buf;
- return msg;
-}
-
-/* get next record; idx must point to valid msg */
-static u32 log_next(u32 idx)
-{
- struct printk_log *msg = (struct printk_log *)(log_buf + idx);
-
- /* length == 0 indicates the end of the buffer; wrap */
- /*
- * A length == 0 record is the end of buffer marker. Wrap around and
- * read the message at the start of the buffer as *this* one, and
- * return the one after that.
- */
- if (!msg->len) {
- msg = (struct printk_log *)log_buf;
- return msg->len;
- }
- return idx + msg->len;
-}
-
static void printk_emergency(char *buffer, int level, u64 ts_nsec, u16 cpu,
char *text, u16 text_len);

@@ -2063,9 +2031,7 @@ EXPORT_SYMBOL(printk);
#define printk_time false

static u64 syslog_seq;
-static u64 log_first_seq;
static u32 log_first_idx;
-static u64 log_next_seq;
static char *log_text(const struct printk_log *msg) { return NULL; }
static char *log_dict(const struct printk_log *msg) { return NULL; }
static struct printk_log *log_from_idx(u32 idx) { return NULL; }
@@ -2974,7 +2940,6 @@ module_param_named(always_kmsg_dump, always_kmsg_dump, bool, S_IRUGO | S_IWUSR);
void kmsg_dump(enum kmsg_dump_reason reason)
{
struct kmsg_dumper *dumper;
- unsigned long flags;

if ((reason > KMSG_DUMP_OOPS) && !always_kmsg_dump)
return;
@@ -2987,12 +2952,7 @@ void kmsg_dump(enum kmsg_dump_reason reason)
/* initialize iterator with data about the stored records */
dumper->active = true;

- logbuf_lock_irqsave(flags);
- dumper->cur_seq = clear_seq;
- dumper->cur_idx = clear_idx;
- dumper->next_seq = log_next_seq;
- dumper->next_idx = log_next_idx;
- logbuf_unlock_irqrestore(flags);
+ kmsg_dump_rewind(dumper);

/* invoke dumper which will iterate over records */
dumper->dump(dumper, reason);
@@ -3025,33 +2985,67 @@ void kmsg_dump(enum kmsg_dump_reason reason)
bool kmsg_dump_get_line_nolock(struct kmsg_dumper *dumper, bool syslog,
char *line, size_t size, size_t *len)
{
+ struct prb_iterator iter;
struct printk_log *msg;
- size_t l = 0;
- bool ret = false;
+ struct prb_handle h;
+ bool cont = false;
+ char *msgbuf;
+ char *rbuf;
+ size_t l;
+ u64 seq;
+ int ret;

if (!dumper->active)
- goto out;
+ return cont;

- if (dumper->cur_seq < log_first_seq) {
- /* messages are gone, move to first available one */
- dumper->cur_seq = log_first_seq;
- dumper->cur_idx = log_first_idx;
+ rbuf = prb_reserve(&h, &sprint_rb, PRINTK_RECORD_MAX);
+ if (!rbuf)
+ return cont;
+ msgbuf = rbuf;
+retry:
+ for (;;) {
+ prb_iter_init(&iter, &printk_rb, &seq);
+
+ if (dumper->line_seq == seq) {
+ /* already where we want to be */
+ break;
+ } else if (dumper->line_seq < seq) {
+ /* messages are gone, move to first available one */
+ dumper->line_seq = seq;
+ break;
+ }
+
+ ret = prb_iter_seek(&iter, dumper->line_seq);
+ if (ret > 0) {
+ /* seeked to line_seq */
+ break;
+ } else if (ret == 0) {
+ /*
+ * The end of the list was hit without ever seeing
+ * line_seq. Reset it to the beginning of the list.
+ */
+ prb_iter_init(&iter, &printk_rb, &dumper->line_seq);
+ break;
+ }
+ /* iterator invalid, start over */
}

- /* last entry */
- if (dumper->cur_seq >= log_next_seq)
+ ret = prb_iter_next(&iter, msgbuf, PRINTK_RECORD_MAX,
+ &dumper->line_seq);
+ if (ret == 0)
goto out;
+ else if (ret < 0)
+ goto retry;

- msg = log_from_idx(dumper->cur_idx);
+ msg = (struct printk_log *)msgbuf;
l = msg_print_text(msg, syslog, printk_time, line, size);

- dumper->cur_idx = log_next(dumper->cur_idx);
- dumper->cur_seq++;
- ret = true;
-out:
if (len)
*len = l;
- return ret;
+ cont = true;
+out:
+ prb_commit(&h);
+ return cont;
}

/**
@@ -3074,12 +3068,11 @@ bool kmsg_dump_get_line_nolock(struct kmsg_dumper *dumper, bool syslog,
bool kmsg_dump_get_line(struct kmsg_dumper *dumper, bool syslog,
char *line, size_t size, size_t *len)
{
- unsigned long flags;
bool ret;

- logbuf_lock_irqsave(flags);
+ mutex_lock(&kmsg_dump_lock);
ret = kmsg_dump_get_line_nolock(dumper, syslog, line, size, len);
- logbuf_unlock_irqrestore(flags);
+ mutex_unlock(&kmsg_dump_lock);

return ret;
}
@@ -3107,74 +3100,101 @@ EXPORT_SYMBOL_GPL(kmsg_dump_get_line);
bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
char *buf, size_t size, size_t *len)
{
- unsigned long flags;
- u64 seq;
- u32 idx;
- u64 next_seq;
- u32 next_idx;
- size_t l = 0;
- bool ret = false;
+ struct prb_iterator iter;
bool time = printk_time;
+ struct printk_log *msg;
+ u64 new_end_seq = 0;
+ struct prb_handle h;
+ bool cont = false;
+ char *msgbuf;
+ u64 end_seq;
+ int textlen;
+ u64 seq = 0;
+ char *rbuf;
+ int l = 0;
+ int ret;

if (!dumper->active)
- goto out;
+ return cont;

- logbuf_lock_irqsave(flags);
- if (dumper->cur_seq < log_first_seq) {
- /* messages are gone, move to first available one */
- dumper->cur_seq = log_first_seq;
- dumper->cur_idx = log_first_idx;
- }
+ rbuf = prb_reserve(&h, &sprint_rb, PRINTK_RECORD_MAX);
+ if (!rbuf)
+ return cont;
+ msgbuf = rbuf;

- /* last entry */
- if (dumper->cur_seq >= dumper->next_seq) {
- logbuf_unlock_irqrestore(flags);
- goto out;
- }
+ prb_iter_init(&iter, &printk_rb, NULL);

- /* calculate length of entire buffer */
- seq = dumper->cur_seq;
- idx = dumper->cur_idx;
- while (seq < dumper->next_seq) {
- struct printk_log *msg = log_from_idx(idx);
+ /*
+ * seek to the start record, which is set/modified
+ * by kmsg_dump_get_line_nolock()
+ */
+ ret = prb_iter_seek(&iter, dumper->line_seq);
+ if (ret <= 0)
+ prb_iter_init(&iter, &printk_rb, &seq);
+
+ /* work with a local end seq to have a constant value */
+ end_seq = dumper->buffer_end_seq;
+ if (!end_seq) {
+ /* initialize end seq to "infinity" */
+ end_seq = -1;
+ dumper->buffer_end_seq = end_seq;
+ }
+retry:
+ if (seq >= end_seq)
+ goto out;

- l += msg_print_text(msg, true, time, NULL, 0);
- idx = log_next(idx);
- seq++;
- }
+ /* count the total bytes after seq */
+ textlen = count_remaining(&iter, end_seq, msgbuf,
+ PRINTK_RECORD_MAX, 0, time);

- /* move first record forward until length fits into the buffer */
- seq = dumper->cur_seq;
- idx = dumper->cur_idx;
- while (l > size && seq < dumper->next_seq) {
- struct printk_log *msg = log_from_idx(idx);
+ /* move iter forward until length fits into the buffer */
+ while (textlen > size) {
+ ret = prb_iter_next(&iter, msgbuf, PRINTK_RECORD_MAX, &seq);
+ if (ret == 0) {
+ break;
+ } else if (ret < 0) {
+ prb_iter_init(&iter, &printk_rb, &seq);
+ goto retry;
+ }

- l -= msg_print_text(msg, true, time, NULL, 0);
- idx = log_next(idx);
- seq++;
+ msg = (struct printk_log *)msgbuf;
+ textlen -= msg_print_text(msg, true, time, NULL, 0);
}

- /* last message in next interation */
- next_seq = seq;
- next_idx = idx;
+ /* save end seq for the next interation */
+ new_end_seq = seq + 1;

- l = 0;
- while (seq < dumper->next_seq) {
- struct printk_log *msg = log_from_idx(idx);
+ /* copy messages to buffer */
+ while (l < size) {
+ ret = prb_iter_next(&iter, msgbuf, PRINTK_RECORD_MAX, &seq);
+ if (ret == 0) {
+ break;
+ } else if (ret < 0) {
+ /*
+ * iterator (and thus also the start position)
+ * invalid, start over from beginning of list
+ */
+ prb_iter_init(&iter, &printk_rb, NULL);
+ continue;
+ }

- l += msg_print_text(msg, syslog, time, buf + l, size - l);
- idx = log_next(idx);
- seq++;
+ if (seq >= end_seq)
+ break;
+
+ msg = (struct printk_log *)msgbuf;
+ textlen = msg_print_text(msg, syslog, time, buf + l, size - l);
+ if (textlen > 0)
+ l += textlen;
+ cont = true;
}

- dumper->next_seq = next_seq;
- dumper->next_idx = next_idx;
- ret = true;
- logbuf_unlock_irqrestore(flags);
-out:
- if (len)
+ if (cont && len)
*len = l;
- return ret;
+out:
+ prb_commit(&h);
+ if (new_end_seq)
+ dumper->buffer_end_seq = new_end_seq;
+ return cont;
}
EXPORT_SYMBOL_GPL(kmsg_dump_get_buffer);

@@ -3190,10 +3210,8 @@ EXPORT_SYMBOL_GPL(kmsg_dump_get_buffer);
*/
void kmsg_dump_rewind_nolock(struct kmsg_dumper *dumper)
{
- dumper->cur_seq = clear_seq;
- dumper->cur_idx = clear_idx;
- dumper->next_seq = log_next_seq;
- dumper->next_idx = log_next_idx;
+ dumper->line_seq = 0;
+ dumper->buffer_end_seq = 0;
}

/**
@@ -3206,11 +3224,9 @@ void kmsg_dump_rewind_nolock(struct kmsg_dumper *dumper)
*/
void kmsg_dump_rewind(struct kmsg_dumper *dumper)
{
- unsigned long flags;
-
- logbuf_lock_irqsave(flags);
+ mutex_lock(&kmsg_dump_lock);
kmsg_dump_rewind_nolock(dumper);
- logbuf_unlock_irqrestore(flags);
+ mutex_unlock(&kmsg_dump_lock);
}
EXPORT_SYMBOL_GPL(kmsg_dump_rewind);

--
2.11.0