Received-SPF: pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) client-ip=209.132.180.67;
From:   John Ogness <john.ogness@linutronix.de>
To:     linux-kernel@vger.kernel.org
Cc:     Peter Zijlstra <peterz@infradead.org>,
        Petr Mladek <pmladek@suse.com>,
        Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com>,
        Steven Rostedt <rostedt@goodmis.org>,
        Daniel Wang <wonderfly@google.com>,
        Andrew Morton <akpm@linux-foundation.org>,
        Linus Torvalds <torvalds@linux-foundation.org>,
        Greg Kroah-Hartman <gregkh@linuxfoundation.org>,
        Alan Cox <gnomes@lxorguk.ukuu.org.uk>,
        Jiri Slaby <jslaby@suse.com>,
        Peter Feiner <pfeiner@google.com>,
        linux-serial@vger.kernel.org,
        Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
Subject: [RFC PATCH v1 24/25] printk: implement kmsg_dump
Date:   Tue, 12 Feb 2019 15:30:02 +0100
Message-Id: <20190212143003.48446-25-john.ogness@linutronix.de>
In-Reply-To: <20190212143003.48446-1-john.ogness@linutronix.de>
References: <20190212143003.48446-1-john.ogness@linutronix.de>
Sender: linux-kernel-owner@vger.kernel.org
Precedence: bulk

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@linutronix.de>
---
 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