[PATCH printk-rework 00/14] printk: remove logbuf_lock

[PATCH printk-rework 00/14] printk: remove logbuf_lock

[John Ogness]

Hello,

Here is v2 of a series to remove @logbuf_lock, exposing the
ringbuffer locklessly to both readers and writers. v1 is here [0].

Since @logbuf_lock was protecting much more than just the
ringbuffer, this series clarifies and cleans up the various
protections using comments, lockless accessors, atomic types, and a
new finer-grained @syslog_log.

Changes since v1:

- handle the syslog_print_all() size calculation issue in a separate
  patch (patch 1)

- use a local printk_info for find_first_fitting_seq()

- define CONSOLE_LOG_MAX in printk.c instead of printk.h since it is
  not used outside of printk.c

- increase CONSOLE_LOG_MAX to 4096 to support long multi-line
  records

- add a wrapper function read_syslog_seq_irq() for getting a
  consistent @syslog_seq value (only used in do_syslog())

- drop the "hv: synchronize kmsg_dumper" patch

- in "remove logbuf_lock" only change to safe buffer usage

- fixup safe buffer usage and redundance in separate patches
  (patches 13 and 14)

- update comments and commit messages as requested

John Ogness

[0] https://lkml.kernel.org/r/20210126211551.26536-1-john.ogness@linutronix.de

John Ogness (14):
  printk: limit second loop of syslog_print_all
  printk: kmsg_dump: remove unused fields
  printk: refactor kmsg_dump_get_buffer()
  printk: consolidate kmsg_dump_get_buffer/syslog_print_all code
  printk: introduce CONSOLE_LOG_MAX for improved multi-line support
  printk: use seqcount_latch for clear_seq
  printk: use atomic64_t for devkmsg_user.seq
  printk: add syslog_lock
  printk: introduce a kmsg_dump iterator
  um: synchronize kmsg_dumper
  printk: remove logbuf_lock
  printk: kmsg_dump: remove _nolock() variants
  printk: kmsg_dump: use kmsg_dump_rewind
  printk: console: remove unnecessary safe buffer usage

 arch/powerpc/kernel/nvram_64.c             |  12 +-
 arch/powerpc/platforms/powernv/opal-kmsg.c |   3 +-
 arch/powerpc/xmon/xmon.c                   |   6 +-
 arch/um/kernel/kmsg_dump.c                 |  13 +-
 drivers/hv/vmbus_drv.c                     |   5 +-
 drivers/mtd/mtdoops.c                      |   5 +-
 fs/pstore/platform.c                       |   5 +-
 include/linux/kmsg_dump.h                  |  52 +--
 kernel/debug/kdb/kdb_main.c                |  10 +-
 kernel/printk/internal.h                   |   4 +-
 kernel/printk/printk.c                     | 454 +++++++++++----------
 kernel/printk/printk_safe.c                |  29 +-
 12 files changed, 298 insertions(+), 300 deletions(-)

-- 
2.20.1

[PATCH printk-rework 01/14] printk: limit second loop of syslog_print_all

[John Ogness]

The second loop of syslog_print_all() subtracts lengths that were
added in the first loop. With commit b031a684bfd0 ("printk: remove
logbuf_lock writer-protection of ringbuffer") it is possible that
records are (over)written during syslog_print_all(). This allows the
possibility of the second loop subtracting lengths that were never
added in the first loop.

This situation can result in syslog_print_all() filling the buffer
starting from a later record, even though there may have been room
to fit the earlier record(s) as well.

Fixes: b031a684bfd0 ("printk: remove logbuf_lock writer-protection of ringbuffer")
Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
 kernel/printk/printk.c | 9 ++++++++-
 1 file changed, 8 insertions(+), 1 deletion(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index c7239d169bbe..411787b900ac 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1495,6 +1495,7 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
 	struct printk_info info;
 	unsigned int line_count;
 	struct printk_record r;
+	u64 max_seq;
 	char *text;
 	int len = 0;
 	u64 seq;
@@ -1513,9 +1514,15 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
 	prb_for_each_info(clear_seq, prb, seq, &info, &line_count)
 		len += get_record_print_text_size(&info, line_count, true, time);
 
+	/*
+	 * Set an upper bound for the next loop to avoid subtracting lengths
+	 * that were never added.
+	 */
+	max_seq = seq;
+
 	/* move first record forward until length fits into the buffer */
 	prb_for_each_info(clear_seq, prb, seq, &info, &line_count) {
-		if (len <= size)
+		if (len <= size || info.seq >= max_seq)
 			break;
 		len -= get_record_print_text_size(&info, line_count, true, time);
 	}
-- 
2.20.1

Re: [PATCH printk-rework 01/14] printk: limit second loop of syslog_print_all

[Petr Mladek]

On Thu 2021-02-18 09:18:04, John Ogness wrote:
> The second loop of syslog_print_all() subtracts lengths that were
> added in the first loop. With commit b031a684bfd0 ("printk: remove
> logbuf_lock writer-protection of ringbuffer") it is possible that
> records are (over)written during syslog_print_all(). This allows the
> possibility of the second loop subtracting lengths that were never
> added in the first loop.
> 
> This situation can result in syslog_print_all() filling the buffer
> starting from a later record, even though there may have been room
> to fit the earlier record(s) as well.
> 
> Fixes: b031a684bfd0 ("printk: remove logbuf_lock writer-protection of ringbuffer")
> Signed-off-by: John Ogness <john.ogness@linutronix.de>

It makes sense after all. We reach the limit only when many old
messages has got replaced. It means that there is a flood
of messages. And this limit looks like a reasonable point where
to start filling the provided buffer.

Reviewed-by: Petr Mladek <pmladek@suse.com>

Best Regards,
Petr

[PATCH printk-rework 02/14] printk: kmsg_dump: remove unused fields

[John Ogness]

struct kmsg_dumper still contains some fields that were used to
iterate the old ringbuffer. They are no longer used. Remove them
and update the struct documentation.

Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
 include/linux/kmsg_dump.h | 5 +++--
 1 file changed, 3 insertions(+), 2 deletions(-)

diff --git a/include/linux/kmsg_dump.h b/include/linux/kmsg_dump.h
index 3378bcbe585e..235c50982c2d 100644
--- a/include/linux/kmsg_dump.h
+++ b/include/linux/kmsg_dump.h
@@ -36,6 +36,9 @@ enum kmsg_dump_reason {
  * 		through the record iterator
  * @max_reason:	filter for highest reason number that should be dumped
  * @registered:	Flag that specifies if this is already registered
+ * @active:	Flag that specifies if this is currently dumping
+ * @cur_seq:	Points to the oldest message to dump (private)
+ * @next_seq:	Points after the newest message to dump (private)
  */
 struct kmsg_dumper {
 	struct list_head list;
@@ -45,8 +48,6 @@ struct kmsg_dumper {
 	bool registered;
 
 	/* private state of the kmsg iterator */
-	u32 cur_idx;
-	u32 next_idx;
 	u64 cur_seq;
 	u64 next_seq;
 };
-- 
2.20.1

Re: [PATCH printk-rework 02/14] printk: kmsg_dump: remove unused fields

[Petr Mladek]

On Thu 2021-02-18 09:18:05, John Ogness wrote:
> struct kmsg_dumper still contains some fields that were used to
> iterate the old ringbuffer. They are no longer used. Remove them
> and update the struct documentation.
> 
> Signed-off-by: John Ogness <john.ogness@linutronix.de>

Reviewed-by: Petr Mladek <pmladek@suse.com>

Best Regards,
Petr

[PATCH printk-rework 03/14] printk: refactor kmsg_dump_get_buffer()

[John Ogness]

kmsg_dump_get_buffer() requires nearly the same logic as
syslog_print_all(), but uses different variable names and
does not make use of the ringbuffer loop macros. Modify
kmsg_dump_get_buffer() so that the implementation is as similar
to syslog_print_all() as possible.

A follow-up commit will move this common logic into a
separate helper function.

Signed-off-by: John Ogness <john.ogness@linutronix.de>
Reviewed-by: Petr Mladek <pmladek@suse.com>
---
 include/linux/kmsg_dump.h |  2 +-
 kernel/printk/printk.c    | 60 +++++++++++++++++++++------------------
 2 files changed, 33 insertions(+), 29 deletions(-)

diff --git a/include/linux/kmsg_dump.h b/include/linux/kmsg_dump.h
index 235c50982c2d..4095a34db0fa 100644
--- a/include/linux/kmsg_dump.h
+++ b/include/linux/kmsg_dump.h
@@ -62,7 +62,7 @@ bool kmsg_dump_get_line(struct kmsg_dumper *dumper, bool syslog,
 			char *line, size_t size, size_t *len);
 
 bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
-			  char *buf, size_t size, size_t *len);
+			  char *buf, size_t size, size_t *len_out);
 
 void kmsg_dump_rewind_nolock(struct kmsg_dumper *dumper);
 
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 411787b900ac..b4f72b5f70b9 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -3420,7 +3420,7 @@ EXPORT_SYMBOL_GPL(kmsg_dump_get_line);
  * read.
  */
 bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
-			  char *buf, size_t size, size_t *len)
+			  char *buf, size_t size, size_t *len_out)
 {
 	struct printk_info info;
 	unsigned int line_count;
@@ -3428,12 +3428,10 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
 	unsigned long flags;
 	u64 seq;
 	u64 next_seq;
-	size_t l = 0;
+	size_t len = 0;
 	bool ret = false;
 	bool time = printk_time;
 
-	prb_rec_init_rd(&r, &info, buf, size);
-
 	if (!dumper->active || !buf || !size)
 		goto out;
 
@@ -3451,48 +3449,54 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
 		goto out;
 	}
 
-	/* calculate length of entire buffer */
-	seq = dumper->cur_seq;
-	while (prb_read_valid_info(prb, seq, &info, &line_count)) {
-		if (r.info->seq >= dumper->next_seq)
+	/*
+	 * Find first record that fits, including all following records,
+	 * into the user-provided buffer for this dump.
+	 */
+
+	prb_for_each_info(dumper->cur_seq, prb, seq, &info, &line_count) {
+		if (info.seq >= dumper->next_seq)
 			break;
-		l += get_record_print_text_size(&info, line_count, syslog, time);
-		seq = r.info->seq + 1;
+		len += get_record_print_text_size(&info, line_count, syslog, time);
 	}
 
-	/* move first record forward until length fits into the buffer */
-	seq = dumper->cur_seq;
-	while (l >= size && prb_read_valid_info(prb, seq,
-						&info, &line_count)) {
-		if (r.info->seq >= dumper->next_seq)
+	/*
+	 * Move first record forward until length fits into the buffer. Ignore
+	 * newest messages that were not counted in the above cycle. Messages
+	 * might appear and get lost in the meantime. This is the best effort
+	 * that prevents an infinite loop.
+	 */
+	prb_for_each_info(dumper->cur_seq, prb, seq, &info, &line_count) {
+		if (len < size || info.seq >= dumper->next_seq)
 			break;
-		l -= get_record_print_text_size(&info, line_count, syslog, time);
-		seq = r.info->seq + 1;
+		len -= get_record_print_text_size(&info, line_count, syslog, time);
 	}
 
-	/* last message in next interation */
+	/*
+	 * Next kmsg_dump_get_buffer() invocation will dump block of
+	 * older records stored right before this one.
+	 */
 	next_seq = seq;
 
-	/* actually read text into the buffer now */
-	l = 0;
-	while (prb_read_valid(prb, seq, &r)) {
+	prb_rec_init_rd(&r, &info, buf, size);
+
+	len = 0;
+	prb_for_each_record(seq, prb, seq, &r) {
 		if (r.info->seq >= dumper->next_seq)
 			break;
 
-		l += record_print_text(&r, syslog, time);
-
-		/* adjust record to store to remaining buffer space */
-		prb_rec_init_rd(&r, &info, buf + l, size - l);
+		len += record_print_text(&r, syslog, time);
 
-		seq = r.info->seq + 1;
+		/* Adjust record to store to remaining buffer space. */
+		prb_rec_init_rd(&r, &info, buf + len, size - len);
 	}
 
 	dumper->next_seq = next_seq;
 	ret = true;
 	logbuf_unlock_irqrestore(flags);
 out:
-	if (len)
-		*len = l;
+	if (len_out)
+		*len_out = len;
 	return ret;
 }
 EXPORT_SYMBOL_GPL(kmsg_dump_get_buffer);
-- 
2.20.1

[PATCH printk-rework 04/14] printk: consolidate kmsg_dump_get_buffer/syslog_print_all code

[John Ogness]

The logic for finding records to fit into a buffer is the same for
kmsg_dump_get_buffer() and syslog_print_all(). Introduce a helper
function find_first_fitting_seq() to handle this logic.

Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
 kernel/printk/printk.c | 87 ++++++++++++++++++++++++------------------
 1 file changed, 50 insertions(+), 37 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index b4f72b5f70b9..d6f93ebd7bd0 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1422,6 +1422,50 @@ static size_t get_record_print_text_size(struct printk_info *info,
 	return ((prefix_len * line_count) + info->text_len + 1);
 }
 
+/*
+ * Beginning with @start_seq, find the first record where it and all following
+ * records up to (but not including) @max_seq fit into @size.
+ *
+ * @max_seq is simply an upper bound and does not need to exist. If the caller
+ * does not require an upper bound, -1 can be used for @max_seq.
+ */
+static u64 find_first_fitting_seq(u64 start_seq, u64 max_seq, size_t size,
+				  bool syslog, bool time)
+{
+	struct printk_info info;
+	unsigned int line_count;
+	size_t len = 0;
+	u64 seq;
+
+	/* Determine the size of the records up to @max_seq. */
+	prb_for_each_info(start_seq, prb, seq, &info, &line_count) {
+		if (info.seq >= max_seq)
+			break;
+		len += get_record_print_text_size(&info, line_count, syslog, time);
+	}
+
+	/*
+	 * Adjust the upper bound for the next loop to avoid subtracting
+	 * lengths that were never added.
+	 */
+	if (seq < max_seq)
+		max_seq = seq;
+
+	/*
+	 * Move first record forward until length fits into the buffer. Ignore
+	 * newest messages that were not counted in the above cycle. Messages
+	 * might appear and get lost in the meantime. This is a best effort
+	 * that prevents an infinite loop that could occur with a retry.
+	 */
+	prb_for_each_info(start_seq, prb, seq, &info, &line_count) {
+		if (len <= size || info.seq >= max_seq)
+			break;
+		len -= get_record_print_text_size(&info, line_count, syslog, time);
+	}
+
+	return seq;
+}
+
 static int syslog_print(char __user *buf, int size)
 {
 	struct printk_info info;
@@ -1493,9 +1537,7 @@ static int syslog_print(char __user *buf, int size)
 static int syslog_print_all(char __user *buf, int size, bool clear)
 {
 	struct printk_info info;
-	unsigned int line_count;
 	struct printk_record r;
-	u64 max_seq;
 	char *text;
 	int len = 0;
 	u64 seq;
@@ -1511,21 +1553,7 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
 	 * Find first record that fits, including all following records,
 	 * into the user-provided buffer for this dump.
 	 */
-	prb_for_each_info(clear_seq, prb, seq, &info, &line_count)
-		len += get_record_print_text_size(&info, line_count, true, time);
-
-	/*
-	 * Set an upper bound for the next loop to avoid subtracting lengths
-	 * that were never added.
-	 */
-	max_seq = seq;
-
-	/* move first record forward until length fits into the buffer */
-	prb_for_each_info(clear_seq, prb, seq, &info, &line_count) {
-		if (len <= size || info.seq >= max_seq)
-			break;
-		len -= get_record_print_text_size(&info, line_count, true, time);
-	}
+	seq = find_first_fitting_seq(clear_seq, -1, size, true, time);
 
 	prb_rec_init_rd(&r, &info, text, LOG_LINE_MAX + PREFIX_MAX);
 
@@ -3423,7 +3451,6 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
 			  char *buf, size_t size, size_t *len_out)
 {
 	struct printk_info info;
-	unsigned int line_count;
 	struct printk_record r;
 	unsigned long flags;
 	u64 seq;
@@ -3451,26 +3478,12 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
 
 	/*
 	 * Find first record that fits, including all following records,
-	 * into the user-provided buffer for this dump.
+	 * into the user-provided buffer for this dump. Pass in size-1
+	 * because this function (by way of record_print_text()) will
+	 * not write more than size-1 bytes of text into @buf.
 	 */
-
-	prb_for_each_info(dumper->cur_seq, prb, seq, &info, &line_count) {
-		if (info.seq >= dumper->next_seq)
-			break;
-		len += get_record_print_text_size(&info, line_count, syslog, time);
-	}
-
-	/*
-	 * Move first record forward until length fits into the buffer. Ignore
-	 * newest messages that were not counted in the above cycle. Messages
-	 * might appear and get lost in the meantime. This is the best effort
-	 * that prevents an infinite loop.
-	 */
-	prb_for_each_info(dumper->cur_seq, prb, seq, &info, &line_count) {
-		if (len < size || info.seq >= dumper->next_seq)
-			break;
-		len -= get_record_print_text_size(&info, line_count, syslog, time);
-	}
+	seq = find_first_fitting_seq(dumper->cur_seq, dumper->next_seq,
+				     size - 1, syslog, time);
 
 	/*
 	 * Next kmsg_dump_get_buffer() invocation will dump block of
-- 
2.20.1

Re: [PATCH printk-rework 04/14] printk: consolidate kmsg_dump_get_buffer/syslog_print_all code

[Petr Mladek]

On Thu 2021-02-18 09:18:07, John Ogness wrote:
> The logic for finding records to fit into a buffer is the same for
> kmsg_dump_get_buffer() and syslog_print_all(). Introduce a helper
> function find_first_fitting_seq() to handle this logic.
> 
> Signed-off-by: John Ogness <john.ogness@linutronix.de>

Reviewed-by: Petr Mladek <pmladek@suse.com>

Best Regards,
Petr

[PATCH printk-rework 05/14] printk: introduce CONSOLE_LOG_MAX for improved multi-line support

[John Ogness]

Instead of using "LOG_LINE_MAX + PREFIX_MAX" for temporary buffer
sizes, introduce CONSOLE_LOG_MAX. This represents the maximum size
that is allowed to be printed to the console for a single record.

Rather than setting CONSOLE_LOG_MAX to "LOG_LINE_MAX + PREFIX_MAX"
(1024), increase it to 4096. With a larger buffer size, multi-line
records that are nearly LOG_LINE_MAX in length will have a better
chance of being fully printed. (When formatting a record for the
console, each line of a multi-line record is prepended with a copy
of the prefix.)

Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
 kernel/printk/printk.c | 18 +++++++++++-------
 1 file changed, 11 insertions(+), 7 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index d6f93ebd7bd0..f79e7515b5f1 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -410,8 +410,13 @@ static u64 clear_seq;
 #else
 #define PREFIX_MAX		32
 #endif
+
+/* the maximum size allowed to be reserved for a record */
 #define LOG_LINE_MAX		(1024 - PREFIX_MAX)
 
+/* the maximum size of a formatted record (i.e. with prefix added per line) */
+#define CONSOLE_LOG_MAX		4096
+
 #define LOG_LEVEL(v)		((v) & 0x07)
 #define LOG_FACILITY(v)		((v) >> 3 & 0xff)
 
@@ -1473,11 +1478,11 @@ static int syslog_print(char __user *buf, int size)
 	char *text;
 	int len = 0;
 
-	text = kmalloc(LOG_LINE_MAX + PREFIX_MAX, GFP_KERNEL);
+	text = kmalloc(CONSOLE_LOG_MAX, GFP_KERNEL);
 	if (!text)
 		return -ENOMEM;
 
-	prb_rec_init_rd(&r, &info, text, LOG_LINE_MAX + PREFIX_MAX);
+	prb_rec_init_rd(&r, &info, text, CONSOLE_LOG_MAX);
 
 	while (size > 0) {
 		size_t n;
@@ -1543,7 +1548,7 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
 	u64 seq;
 	bool time;
 
-	text = kmalloc(LOG_LINE_MAX + PREFIX_MAX, GFP_KERNEL);
+	text = kmalloc(CONSOLE_LOG_MAX, GFP_KERNEL);
 	if (!text)
 		return -ENOMEM;
 
@@ -1555,7 +1560,7 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
 	 */
 	seq = find_first_fitting_seq(clear_seq, -1, size, true, time);
 
-	prb_rec_init_rd(&r, &info, text, LOG_LINE_MAX + PREFIX_MAX);
+	prb_rec_init_rd(&r, &info, text, CONSOLE_LOG_MAX);
 
 	len = 0;
 	prb_for_each_record(seq, prb, seq, &r) {
@@ -2188,8 +2193,7 @@ EXPORT_SYMBOL(printk);
 
 #else /* CONFIG_PRINTK */
 
-#define LOG_LINE_MAX		0
-#define PREFIX_MAX		0
+#define CONSOLE_LOG_MAX		0
 #define printk_time		false
 
 #define prb_read_valid(rb, seq, r)	false
@@ -2500,7 +2504,7 @@ static inline int can_use_console(void)
 void console_unlock(void)
 {
 	static char ext_text[CONSOLE_EXT_LOG_MAX];
-	static char text[LOG_LINE_MAX + PREFIX_MAX];
+	static char text[CONSOLE_LOG_MAX];
 	unsigned long flags;
 	bool do_cond_resched, retry;
 	struct printk_info info;
-- 
2.20.1

Re: [PATCH printk-rework 05/14] printk: introduce CONSOLE_LOG_MAX for improved multi-line support

[Petr Mladek]

On Thu 2021-02-18 09:18:08, John Ogness wrote:
> Instead of using "LOG_LINE_MAX + PREFIX_MAX" for temporary buffer
> sizes, introduce CONSOLE_LOG_MAX. This represents the maximum size
> that is allowed to be printed to the console for a single record.
> 
> Rather than setting CONSOLE_LOG_MAX to "LOG_LINE_MAX + PREFIX_MAX"
> (1024), increase it to 4096. With a larger buffer size, multi-line
> records that are nearly LOG_LINE_MAX in length will have a better
> chance of being fully printed. (When formatting a record for the
> console, each line of a multi-line record is prepended with a copy
> of the prefix.)
> 
> Signed-off-by: John Ogness <john.ogness@linutronix.de>

The logic is correct. I am just slightly afraid that people
developing small devices might cry. And nobody reported problems
with the small buffer.

OK, let's try the change. We could always revert the size increase
when anyone complains.

Reviewed-by: Petr Mladek <pmladek@suse.com>

Best Regards,
Petr

[PATCH printk-rework 06/14] printk: use seqcount_latch for clear_seq

[John Ogness]

kmsg_dump_rewind_nolock() locklessly reads @clear_seq. However,
this is not done atomically. Since @clear_seq is 64-bit, this
cannot be an atomic operation for all platforms. Therefore, use
a seqcount_latch to allow readers to always read a consistent
value.

Signed-off-by: John Ogness <john.ogness@linutronix.de>
Reviewed-by: Petr Mladek <pmladek@suse.com>
---
 kernel/printk/printk.c | 58 ++++++++++++++++++++++++++++++++++++------
 1 file changed, 50 insertions(+), 8 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index f79e7515b5f1..a71e0d41ccb5 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -402,8 +402,21 @@ static u64 console_seq;
 static u64 exclusive_console_stop_seq;
 static unsigned long console_dropped;
 
-/* the next printk record to read after the last 'clear' command */
-static u64 clear_seq;
+struct latched_seq {
+	seqcount_latch_t	latch;
+	u64			val[2];
+};
+
+/*
+ * The next printk record to read after the last 'clear' command. There are
+ * two copies (updated with seqcount_latch) so that reads can locklessly
+ * access a valid value. Writers are synchronized by @logbuf_lock.
+ */
+static struct latched_seq clear_seq = {
+	.latch		= SEQCNT_LATCH_ZERO(clear_seq.latch),
+	.val[0]		= 0,
+	.val[1]		= 0,
+};
 
 #ifdef CONFIG_PRINTK_CALLER
 #define PREFIX_MAX		48
@@ -457,6 +470,31 @@ bool printk_percpu_data_ready(void)
 	return __printk_percpu_data_ready;
 }
 
+/* Must be called under logbuf_lock. */
+static void latched_seq_write(struct latched_seq *ls, u64 val)
+{
+	raw_write_seqcount_latch(&ls->latch);
+	ls->val[0] = val;
+	raw_write_seqcount_latch(&ls->latch);
+	ls->val[1] = val;
+}
+
+/* Can be called from any context. */
+static u64 latched_seq_read_nolock(struct latched_seq *ls)
+{
+	unsigned int seq;
+	unsigned int idx;
+	u64 val;
+
+	do {
+		seq = raw_read_seqcount_latch(&ls->latch);
+		idx = seq & 0x1;
+		val = ls->val[idx];
+	} while (read_seqcount_latch_retry(&ls->latch, seq));
+
+	return val;
+}
+
 /* Return log buffer address */
 char *log_buf_addr_get(void)
 {
@@ -802,7 +840,7 @@ static loff_t devkmsg_llseek(struct file *file, loff_t offset, int whence)
 		 * like issued by 'dmesg -c'. Reading /dev/kmsg itself
 		 * changes no global state, and does not clear anything.
 		 */
-		user->seq = clear_seq;
+		user->seq = latched_seq_read_nolock(&clear_seq);
 		break;
 	case SEEK_END:
 		/* after the last record */
@@ -961,6 +999,9 @@ void log_buf_vmcoreinfo_setup(void)
 
 	VMCOREINFO_SIZE(atomic_long_t);
 	VMCOREINFO_TYPE_OFFSET(atomic_long_t, counter);
+
+	VMCOREINFO_STRUCT_SIZE(latched_seq);
+	VMCOREINFO_OFFSET(latched_seq, val);
 }
 #endif
 
@@ -1558,7 +1599,8 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
 	 * Find first record that fits, including all following records,
 	 * into the user-provided buffer for this dump.
 	 */
-	seq = find_first_fitting_seq(clear_seq, -1, size, true, time);
+	seq = find_first_fitting_seq(latched_seq_read_nolock(&clear_seq), -1,
+				     size, true, time);
 
 	prb_rec_init_rd(&r, &info, text, CONSOLE_LOG_MAX);
 
@@ -1585,7 +1627,7 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
 	}
 
 	if (clear)
-		clear_seq = seq;
+		latched_seq_write(&clear_seq, seq);
 	logbuf_unlock_irq();
 
 	kfree(text);
@@ -1595,7 +1637,7 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
 static void syslog_clear(void)
 {
 	logbuf_lock_irq();
-	clear_seq = prb_next_seq(prb);
+	latched_seq_write(&clear_seq, prb_next_seq(prb));
 	logbuf_unlock_irq();
 }
 
@@ -3332,7 +3374,7 @@ void kmsg_dump(enum kmsg_dump_reason reason)
 		dumper->active = true;
 
 		logbuf_lock_irqsave(flags);
-		dumper->cur_seq = clear_seq;
+		dumper->cur_seq = latched_seq_read_nolock(&clear_seq);
 		dumper->next_seq = prb_next_seq(prb);
 		logbuf_unlock_irqrestore(flags);
 
@@ -3530,7 +3572,7 @@ EXPORT_SYMBOL_GPL(kmsg_dump_get_buffer);
  */
 void kmsg_dump_rewind_nolock(struct kmsg_dumper *dumper)
 {
-	dumper->cur_seq = clear_seq;
+	dumper->cur_seq = latched_seq_read_nolock(&clear_seq);
 	dumper->next_seq = prb_next_seq(prb);
 }
 
-- 
2.20.1

[PATCH printk-rework 07/14] printk: use atomic64_t for devkmsg_user.seq

[John Ogness]

@user->seq is indirectly protected by @logbuf_lock. Once @logbuf_lock
is removed, @user->seq will be no longer safe from an atomicity point
of view.

In preparation for the removal of @logbuf_lock, change it to
atomic64_t to provide this safety.

Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
 kernel/printk/printk.c | 24 ++++++++++++------------
 1 file changed, 12 insertions(+), 12 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index a71e0d41ccb5..20c21a25143d 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -662,7 +662,7 @@ static ssize_t msg_print_ext_body(char *buf, size_t size,
 
 /* /dev/kmsg - userspace message inject/listen interface */
 struct devkmsg_user {
-	u64 seq;
+	atomic64_t seq;
 	struct ratelimit_state rs;
 	struct mutex lock;
 	char buf[CONSOLE_EXT_LOG_MAX];
@@ -764,7 +764,7 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
 		return ret;
 
 	logbuf_lock_irq();
-	if (!prb_read_valid(prb, user->seq, r)) {
+	if (!prb_read_valid(prb, atomic64_read(&user->seq), r)) {
 		if (file->f_flags & O_NONBLOCK) {
 			ret = -EAGAIN;
 			logbuf_unlock_irq();
@@ -773,15 +773,15 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
 
 		logbuf_unlock_irq();
 		ret = wait_event_interruptible(log_wait,
-					prb_read_valid(prb, user->seq, r));
+				prb_read_valid(prb, atomic64_read(&user->seq), r));
 		if (ret)
 			goto out;
 		logbuf_lock_irq();
 	}
 
-	if (r->info->seq != user->seq) {
+	if (r->info->seq != atomic64_read(&user->seq)) {
 		/* our last seen message is gone, return error and reset */
-		user->seq = r->info->seq;
+		atomic64_set(&user->seq, r->info->seq);
 		ret = -EPIPE;
 		logbuf_unlock_irq();
 		goto out;
@@ -792,7 +792,7 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
 				  &r->text_buf[0], r->info->text_len,
 				  &r->info->dev_info);
 
-	user->seq = r->info->seq + 1;
+	atomic64_set(&user->seq, r->info->seq + 1);
 	logbuf_unlock_irq();
 
 	if (len > count) {
@@ -832,7 +832,7 @@ static loff_t devkmsg_llseek(struct file *file, loff_t offset, int whence)
 	switch (whence) {
 	case SEEK_SET:
 		/* the first record */
-		user->seq = prb_first_valid_seq(prb);
+		atomic64_set(&user->seq, prb_first_valid_seq(prb));
 		break;
 	case SEEK_DATA:
 		/*
@@ -840,11 +840,11 @@ static loff_t devkmsg_llseek(struct file *file, loff_t offset, int whence)
 		 * like issued by 'dmesg -c'. Reading /dev/kmsg itself
 		 * changes no global state, and does not clear anything.
 		 */
-		user->seq = latched_seq_read_nolock(&clear_seq);
+		atomic64_set(&user->seq, latched_seq_read_nolock(&clear_seq));
 		break;
 	case SEEK_END:
 		/* after the last record */
-		user->seq = prb_next_seq(prb);
+		atomic64_set(&user->seq, prb_next_seq(prb));
 		break;
 	default:
 		ret = -EINVAL;
@@ -865,9 +865,9 @@ static __poll_t devkmsg_poll(struct file *file, poll_table *wait)
 	poll_wait(file, &log_wait, wait);
 
 	logbuf_lock_irq();
-	if (prb_read_valid_info(prb, user->seq, &info, NULL)) {
+	if (prb_read_valid(prb, atomic64_read(&user->seq), NULL)) {
 		/* return error when data has vanished underneath us */
-		if (info.seq != user->seq)
+		if (info.seq != atomic64_read(&user->seq))
 			ret = EPOLLIN|EPOLLRDNORM|EPOLLERR|EPOLLPRI;
 		else
 			ret = EPOLLIN|EPOLLRDNORM;
@@ -906,7 +906,7 @@ static int devkmsg_open(struct inode *inode, struct file *file)
 			&user->text_buf[0], sizeof(user->text_buf));
 
 	logbuf_lock_irq();
-	user->seq = prb_first_valid_seq(prb);
+	atomic64_set(&user->seq, prb_first_valid_seq(prb));
 	logbuf_unlock_irq();
 
 	file->private_data = user;
-- 
2.20.1

Re: [PATCH printk-rework 07/14] printk: use atomic64_t for devkmsg_user.seq

[Petr Mladek]

On Thu 2021-02-18 09:18:10, John Ogness wrote:
> @user->seq is indirectly protected by @logbuf_lock. Once @logbuf_lock
> is removed, @user->seq will be no longer safe from an atomicity point
> of view.
> 
> In preparation for the removal of @logbuf_lock, change it to
> atomic64_t to provide this safety.
> 
> Signed-off-by: John Ogness <john.ogness@linutronix.de>
> ---
>  kernel/printk/printk.c | 24 ++++++++++++------------
>  1 file changed, 12 insertions(+), 12 deletions(-)
> 
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index a71e0d41ccb5..20c21a25143d 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -865,9 +865,9 @@ static __poll_t devkmsg_poll(struct file *file, poll_table *wait)
>  	poll_wait(file, &log_wait, wait);
>  
>  	logbuf_lock_irq();
> -	if (prb_read_valid_info(prb, user->seq, &info, NULL)) {
> +	if (prb_read_valid(prb, atomic64_read(&user->seq), NULL)) {

s/prb_read_valid/prb_read_valid_info/

It is likely a mistake when rebasing on top of the commit
13791c80b0cdf54d ("printk: avoid prb_first_valid_seq() where possible").

>  		/* return error when data has vanished underneath us */
> -		if (info.seq != user->seq)
> +		if (info.seq != atomic64_read(&user->seq))
>  			ret = EPOLLIN|EPOLLRDNORM|EPOLLERR|EPOLLPRI;
>  		else
>  			ret = EPOLLIN|EPOLLRDNORM;

With the above fix:

Reviewed-by: Petr Mladek <pmladek@suse.com>

Best Regards,
Petr

[PATCH printk-rework 08/14] printk: add syslog_lock

[John Ogness]

The global variables @syslog_seq, @syslog_partial, @syslog_time
and write access to @clear_seq are protected by @logbuf_lock.
Once @logbuf_lock is removed, these variables will need their
own synchronization method. Introduce @syslog_lock for this
purpose.

@syslog_lock is a raw_spin_lock for now. This simplifies the
transition to removing @logbuf_lock. Once @logbuf_lock and the
safe buffers are removed, @syslog_lock can change to spin_lock.

Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
 kernel/printk/printk.c | 41 +++++++++++++++++++++++++++++++++++++----
 1 file changed, 37 insertions(+), 4 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 20c21a25143d..401df370832b 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -390,8 +390,12 @@ DEFINE_RAW_SPINLOCK(logbuf_lock);
 		printk_safe_exit_irqrestore(flags);	\
 	} while (0)
 
+/* syslog_lock protects syslog_* variables and write access to clear_seq. */
+static DEFINE_RAW_SPINLOCK(syslog_lock);
+
 #ifdef CONFIG_PRINTK
 DECLARE_WAIT_QUEUE_HEAD(log_wait);
+/* All 3 protected by @syslog_lock. */
 /* the next printk record to read by syslog(READ) or /proc/kmsg */
 static u64 syslog_seq;
 static size_t syslog_partial;
@@ -410,7 +414,7 @@ struct latched_seq {
 /*
  * The next printk record to read after the last 'clear' command. There are
  * two copies (updated with seqcount_latch) so that reads can locklessly
- * access a valid value. Writers are synchronized by @logbuf_lock.
+ * access a valid value. Writers are synchronized by @syslog_lock.
  */
 static struct latched_seq clear_seq = {
 	.latch		= SEQCNT_LATCH_ZERO(clear_seq.latch),
@@ -470,7 +474,7 @@ bool printk_percpu_data_ready(void)
 	return __printk_percpu_data_ready;
 }
 
-/* Must be called under logbuf_lock. */
+/* Must be called under syslog_lock. */
 static void latched_seq_write(struct latched_seq *ls, u64 val)
 {
 	raw_write_seqcount_latch(&ls->latch);
@@ -1530,7 +1534,9 @@ static int syslog_print(char __user *buf, int size)
 		size_t skip;
 
 		logbuf_lock_irq();
+		raw_spin_lock(&syslog_lock);
 		if (!prb_read_valid(prb, syslog_seq, &r)) {
+			raw_spin_unlock(&syslog_lock);
 			logbuf_unlock_irq();
 			break;
 		}
@@ -1560,6 +1566,7 @@ static int syslog_print(char __user *buf, int size)
 			syslog_partial += n;
 		} else
 			n = 0;
+		raw_spin_unlock(&syslog_lock);
 		logbuf_unlock_irq();
 
 		if (!n)
@@ -1626,8 +1633,11 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
 			break;
 	}
 
-	if (clear)
+	if (clear) {
+		raw_spin_lock(&syslog_lock);
 		latched_seq_write(&clear_seq, seq);
+		raw_spin_unlock(&syslog_lock);
+	}
 	logbuf_unlock_irq();
 
 	kfree(text);
@@ -1637,10 +1647,24 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
 static void syslog_clear(void)
 {
 	logbuf_lock_irq();
+	raw_spin_lock(&syslog_lock);
 	latched_seq_write(&clear_seq, prb_next_seq(prb));
+	raw_spin_unlock(&syslog_lock);
 	logbuf_unlock_irq();
 }
 
+/* Return a consistent copy of @syslog_seq. */
+static u64 read_syslog_seq_irq(void)
+{
+	u64 seq;
+
+	raw_spin_lock_irq(&syslog_lock);
+	seq = syslog_seq;
+	raw_spin_unlock_irq(&syslog_lock);
+
+	return seq;
+}
+
 int do_syslog(int type, char __user *buf, int len, int source)
 {
 	struct printk_info info;
@@ -1664,8 +1688,9 @@ int do_syslog(int type, char __user *buf, int len, int source)
 			return 0;
 		if (!access_ok(buf, len))
 			return -EFAULT;
+
 		error = wait_event_interruptible(log_wait,
-				prb_read_valid(prb, syslog_seq, NULL));
+				prb_read_valid(prb, read_syslog_seq_irq(), NULL));
 		if (error)
 			return error;
 		error = syslog_print(buf, len);
@@ -1714,8 +1739,10 @@ int do_syslog(int type, char __user *buf, int len, int source)
 	/* Number of chars in the log buffer */
 	case SYSLOG_ACTION_SIZE_UNREAD:
 		logbuf_lock_irq();
+		raw_spin_lock(&syslog_lock);
 		if (!prb_read_valid_info(prb, syslog_seq, &info, NULL)) {
 			/* No unread messages. */
+			raw_spin_unlock(&syslog_lock);
 			logbuf_unlock_irq();
 			return 0;
 		}
@@ -1744,6 +1771,7 @@ int do_syslog(int type, char __user *buf, int len, int source)
 			}
 			error -= syslog_partial;
 		}
+		raw_spin_unlock(&syslog_lock);
 		logbuf_unlock_irq();
 		break;
 	/* Size of the log buffer */
@@ -2986,7 +3014,12 @@ void register_console(struct console *newcon)
 		 */
 		exclusive_console = newcon;
 		exclusive_console_stop_seq = console_seq;
+
+		/* Get a consistent copy of @syslog_seq. */
+		raw_spin_lock(&syslog_lock);
 		console_seq = syslog_seq;
+		raw_spin_unlock(&syslog_lock);
+
 		logbuf_unlock_irqrestore(flags);
 	}
 	console_unlock();
-- 
2.20.1

Re: [PATCH printk-rework 08/14] printk: add syslog_lock

[Petr Mladek]

On Thu 2021-02-18 09:18:11, John Ogness wrote:
> The global variables @syslog_seq, @syslog_partial, @syslog_time
> and write access to @clear_seq are protected by @logbuf_lock.
> Once @logbuf_lock is removed, these variables will need their
> own synchronization method. Introduce @syslog_lock for this
> purpose.
> 
> @syslog_lock is a raw_spin_lock for now. This simplifies the
> transition to removing @logbuf_lock. Once @logbuf_lock and the
> safe buffers are removed, @syslog_lock can change to spin_lock.
> ---
>  kernel/printk/printk.c | 41 +++++++++++++++++++++++++++++++++++++----
>  1 file changed, 37 insertions(+), 4 deletions(-)
> 
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 20c21a25143d..401df370832b 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> +/* Return a consistent copy of @syslog_seq. */
> +static u64 read_syslog_seq_irq(void)
> +{
> +	u64 seq;
> +
> +	raw_spin_lock_irq(&syslog_lock);
> +	seq = syslog_seq;
> +	raw_spin_unlock_irq(&syslog_lock);

Is there any particular reason to disable interrupts here?

It would make sense only when the lock could be taken in IRQ
context. Then we would need to always disable interrupts when
the lock is taken. And if it is taken in IRQ context, we would
need to safe flags.

I guess that you got confused because it is used in
wait_event_interruptible(). The name is misleading.
"interruptible" means wake_up_process() and not IRQ here.

IMHO, we should remove _irq suffix from the lock operations
and also from the function name.

> +
> +	return seq;
> +}
> +
>  int do_syslog(int type, char __user *buf, int len, int source)
>  {
>  	struct printk_info info;
> @@ -1664,8 +1688,9 @@ int do_syslog(int type, char __user *buf, int len, int source)
>  			return 0;
>  		if (!access_ok(buf, len))
>  			return -EFAULT;
> +
>  		error = wait_event_interruptible(log_wait,
> -				prb_read_valid(prb, syslog_seq, NULL));
> +				prb_read_valid(prb, read_syslog_seq_irq(), NULL));
>  		if (error)
>  			return error;
>  		error = syslog_print(buf, len);

Otherwise, the patch looks good to me.

Best Regards,
Petr

Re: [PATCH printk-rework 08/14] printk: add syslog_lock

[John Ogness]

On 2021-02-19, Petr Mladek <pmladek@suse.com> wrote:
>> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
>> index 20c21a25143d..401df370832b 100644
>> --- a/kernel/printk/printk.c
>> +++ b/kernel/printk/printk.c
>> +/* Return a consistent copy of @syslog_seq. */
>> +static u64 read_syslog_seq_irq(void)
>> +{
>> +	u64 seq;
>> +
>> +	raw_spin_lock_irq(&syslog_lock);
>> +	seq = syslog_seq;
>> +	raw_spin_unlock_irq(&syslog_lock);
>
> Is there any particular reason to disable interrupts here?
>
> It would make sense only when the lock could be taken in IRQ
> context. Then we would need to always disable interrupts when
> the lock is taken. And if it is taken in IRQ context, we would
> need to safe flags.

All other instances of locking @syslog_lock are done with interrupts
disabled. And we have:

register_console()
  logbuf_lock_irqsave()
    raw_spin_lock(&syslog_lock)

Looking back through history, I found that locking of the "console lock"
in register_console() was changed from spin_lock_irq() to
spin_lock_irqsave() for 2.3.15pre1 [0]. The only reason I can find why
that was done is because sparc64 was regstering its console in a PROM
callback (the comments there: "Pretty sick eh?").

Today sparc64 is setting up the console in init code. I suppose I need
to go through all the console drivers to see if any register in
interrupt context. If not, that logbuf_lock_irqsave() should be replaced
with logbuf_lock_irq(). And then locking @syslog_lock will not need to
disable interrupts.

John Ogness

[0] https://github.com/schwabe/davej-history/commit/f91c3404ba16c88cdb33824bf0249c6263cd4465#diff-84036d1e27f4207c783a3b876aef4e45340d30f43b1319bca382f5775a9b14beL348

Re: [PATCH printk-rework 08/14] printk: add syslog_lock

[John Ogness]

Added CC: linux-parisc@vger.kernel.org

On 2021-02-19, John Ogness <john.ogness@linutronix.de> wrote:
>>> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
>>> index 20c21a25143d..401df370832b 100644
>>> --- a/kernel/printk/printk.c
>>> +++ b/kernel/printk/printk.c
>>> +/* Return a consistent copy of @syslog_seq. */
>>> +static u64 read_syslog_seq_irq(void)
>>> +{
>>> +	u64 seq;
>>> +
>>> +	raw_spin_lock_irq(&syslog_lock);
>>> +	seq = syslog_seq;
>>> +	raw_spin_unlock_irq(&syslog_lock);
>>
>> Is there any particular reason to disable interrupts here?
>>
>> It would make sense only when the lock could be taken in IRQ
>> context. Then we would need to always disable interrupts when
>> the lock is taken. And if it is taken in IRQ context, we would
>> need to safe flags.
>
> All other instances of locking @syslog_lock are done with interrupts
> disabled. And we have:
>
> register_console()
>   logbuf_lock_irqsave()
>     raw_spin_lock(&syslog_lock)
>
> I suppose I need to go through all the console drivers to see if any
> register in interrupt context. If not, that logbuf_lock_irqsave()
> should be replaced with logbuf_lock_irq(). And then locking
> @syslog_lock will not need to disable interrupts.

I found a possible call chain in interrupt context. From arch/parisc
there is the interrupt handler:

handle_interruption(code=1) /* High-priority machine check (HPMC) */
  pdc_console_restart()
    pdc_console_init_force()
      register_console()

All other register_console() calls in the kernel are either during init
(within __init sections and probe functions) or are clearly not in
interrupt context (using mutex, kzalloc, spin_lock_irq, etc).

I am not familiar with parisc, but I am assuming handle_interruption()
is always called with interrupts disabled (unless the HPMC interrupt is
somehow an exception).

John Ogness

Re: [PATCH printk-rework 08/14] printk: add syslog_lock

[Helge Deller]

On 2/19/21 5:33 PM, John Ogness wrote:
> Added CC: linux-parisc@vger.kernel.org
>
> On 2021-02-19, John Ogness <john.ogness@linutronix.de> wrote:
>>>> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
>>>> index 20c21a25143d..401df370832b 100644
>>>> --- a/kernel/printk/printk.c
>>>> +++ b/kernel/printk/printk.c
>>>> +/* Return a consistent copy of @syslog_seq. */
>>>> +static u64 read_syslog_seq_irq(void)
>>>> +{
>>>> +	u64 seq;
>>>> +
>>>> +	raw_spin_lock_irq(&syslog_lock);
>>>> +	seq = syslog_seq;
>>>> +	raw_spin_unlock_irq(&syslog_lock);
>>>
>>> Is there any particular reason to disable interrupts here?
>>>
>>> It would make sense only when the lock could be taken in IRQ
>>> context. Then we would need to always disable interrupts when
>>> the lock is taken. And if it is taken in IRQ context, we would
>>> need to safe flags.
>>
>> All other instances of locking @syslog_lock are done with interrupts
>> disabled. And we have:
>>
>> register_console()
>>    logbuf_lock_irqsave()
>>      raw_spin_lock(&syslog_lock)
>>
>> I suppose I need to go through all the console drivers to see if any
>> register in interrupt context. If not, that logbuf_lock_irqsave()
>> should be replaced with logbuf_lock_irq(). And then locking
>> @syslog_lock will not need to disable interrupts.
>
> I found a possible call chain in interrupt context. From arch/parisc
> there is the interrupt handler:
>
> handle_interruption(code=1) /* High-priority machine check (HPMC) */
>    pdc_console_restart()
>      pdc_console_init_force()
>        register_console()
>
> All other register_console() calls in the kernel are either during init
> (within __init sections and probe functions) or are clearly not in
> interrupt context (using mutex, kzalloc, spin_lock_irq, etc).
>
> I am not familiar with parisc, but I am assuming handle_interruption()
> is always called with interrupts disabled (unless the HPMC interrupt is
> somehow an exception).

Yes, handle_interruption() is the irq handler, running with irqs off.
HPMC is the crash handler - it's called when the kernel will stop
anyway. pdc_console is a very basic firmware console which prints
the last messages before the machine halts on fatal errors.
So, this code it's not the typical use case....

Helge

Re: [PATCH printk-rework 08/14] printk: add syslog_lock

[Petr Mladek]

On Sun 2021-02-21 22:39:42, Helge Deller wrote:
> On 2/19/21 5:33 PM, John Ogness wrote:
> > Added CC: linux-parisc@vger.kernel.org
> > 
> > On 2021-02-19, John Ogness <john.ogness@linutronix.de> wrote:
> > > > > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> > > > > index 20c21a25143d..401df370832b 100644
> > > > > --- a/kernel/printk/printk.c
> > > > > +++ b/kernel/printk/printk.c
> > > > > +/* Return a consistent copy of @syslog_seq. */
> > > > > +static u64 read_syslog_seq_irq(void)
> > > > > +{
> > > > > +	u64 seq;
> > > > > +
> > > > > +	raw_spin_lock_irq(&syslog_lock);
> > > > > +	seq = syslog_seq;
> > > > > +	raw_spin_unlock_irq(&syslog_lock);
> > > > 
> > > > Is there any particular reason to disable interrupts here?
> > > > 
> > > > It would make sense only when the lock could be taken in IRQ
> > > > context. Then we would need to always disable interrupts when
> > > > the lock is taken. And if it is taken in IRQ context, we would
> > > > need to safe flags.
> > > 
> > > All other instances of locking @syslog_lock are done with interrupts
> > > disabled. And we have:
> > > 
> > > register_console()
> > >    logbuf_lock_irqsave()
> > >      raw_spin_lock(&syslog_lock)
> > > 
> > > I suppose I need to go through all the console drivers to see if any
> > > register in interrupt context. If not, that logbuf_lock_irqsave()
> > > should be replaced with logbuf_lock_irq(). And then locking
> > > @syslog_lock will not need to disable interrupts.
> > 
> > I found a possible call chain in interrupt context. From arch/parisc
> > there is the interrupt handler:
> > 
> > handle_interruption(code=1) /* High-priority machine check (HPMC) */
> >    pdc_console_restart()
> >      pdc_console_init_force()
> >        register_console()
> > 
> > All other register_console() calls in the kernel are either during init
> > (within __init sections and probe functions) or are clearly not in
> > interrupt context (using mutex, kzalloc, spin_lock_irq, etc).
> > 
> > I am not familiar with parisc, but I am assuming handle_interruption()
> > is always called with interrupts disabled (unless the HPMC interrupt is
> > somehow an exception).
> 
> Yes, handle_interruption() is the irq handler, running with irqs off.
> HPMC is the crash handler - it's called when the kernel will stop
> anyway. pdc_console is a very basic firmware console which prints
> the last messages before the machine halts on fatal errors.
> So, this code it's not the typical use case....

Thanks for information.

Is this code supposed to work only during early boot or anytime,
please?

Note that it is not safe because register_console() takes
console_lock() which is a sleeping lock.

That said, we are going to rework the console handling a lot. We are
trying to remove as many locks from the printk path as possible.
I guess that the list of consoles will be synchronized using
rcu at the end. But it is still a long way to go.

Best Regards,
Petr

Re: [PATCH printk-rework 08/14] printk: add syslog_lock

[Helge Deller]

On 2/22/21 5:28 PM, Petr Mladek wrote:
> On Sun 2021-02-21 22:39:42, Helge Deller wrote:
>> On 2/19/21 5:33 PM, John Ogness wrote:
>>> Added CC: linux-parisc@vger.kernel.org
>>>
>>> On 2021-02-19, John Ogness <john.ogness@linutronix.de> wrote:
>>>>>> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
>>>>>> index 20c21a25143d..401df370832b 100644
>>>>>> --- a/kernel/printk/printk.c
>>>>>> +++ b/kernel/printk/printk.c
>>>>>> +/* Return a consistent copy of @syslog_seq. */
>>>>>> +static u64 read_syslog_seq_irq(void)
>>>>>> +{
>>>>>> +	u64 seq;
>>>>>> +
>>>>>> +	raw_spin_lock_irq(&syslog_lock);
>>>>>> +	seq = syslog_seq;
>>>>>> +	raw_spin_unlock_irq(&syslog_lock);
>>>>>
>>>>> Is there any particular reason to disable interrupts here?
>>>>>
>>>>> It would make sense only when the lock could be taken in IRQ
>>>>> context. Then we would need to always disable interrupts when
>>>>> the lock is taken. And if it is taken in IRQ context, we would
>>>>> need to safe flags.
>>>>
>>>> All other instances of locking @syslog_lock are done with interrupts
>>>> disabled. And we have:
>>>>
>>>> register_console()
>>>>     logbuf_lock_irqsave()
>>>>       raw_spin_lock(&syslog_lock)
>>>>
>>>> I suppose I need to go through all the console drivers to see if any
>>>> register in interrupt context. If not, that logbuf_lock_irqsave()
>>>> should be replaced with logbuf_lock_irq(). And then locking
>>>> @syslog_lock will not need to disable interrupts.
>>>
>>> I found a possible call chain in interrupt context. From arch/parisc
>>> there is the interrupt handler:
>>>
>>> handle_interruption(code=1) /* High-priority machine check (HPMC) */
>>>     pdc_console_restart()
>>>       pdc_console_init_force()
>>>         register_console()
>>>
>>> All other register_console() calls in the kernel are either during init
>>> (within __init sections and probe functions) or are clearly not in
>>> interrupt context (using mutex, kzalloc, spin_lock_irq, etc).
>>>
>>> I am not familiar with parisc, but I am assuming handle_interruption()
>>> is always called with interrupts disabled (unless the HPMC interrupt is
>>> somehow an exception).
>>
>> Yes, handle_interruption() is the irq handler, running with irqs off.
>> HPMC is the crash handler - it's called when the kernel will stop
>> anyway. pdc_console is a very basic firmware console which prints
>> the last messages before the machine halts on fatal errors.
>> So, this code it's not the typical use case....
>
> Thanks for information.
>
> Is this code supposed to work only during early boot or anytime,
> please?

No.
It's only called when the kernel completely crashes, when all
spinlocks should get busted and so on.
It's the emergency way to get some info out at least.

> Note that it is not safe because register_console() takes
> console_lock() which is a sleeping lock.

As I said, in that stage the plan is to bust all spinlocks.

> That said, we are going to rework the console handling a lot. We are
> trying to remove as many locks from the printk path as possible.

That's good!

> I guess that the list of consoles will be synchronized using
> rcu at the end. But it is still a long way to go.

I'd say, that you simply should ignore this specific case here.
I'm happy to change anything there, so if you get rid of printk locks
it will benefit here too.

Helge

Re: [PATCH printk-rework 08/14] printk: add syslog_lock

[Petr Mladek]

On Tue 2021-02-23 13:22:22, Helge Deller wrote:
> On 2/22/21 5:28 PM, Petr Mladek wrote:
> > On Sun 2021-02-21 22:39:42, Helge Deller wrote:
> > > On 2/19/21 5:33 PM, John Ogness wrote:
> > > > Added CC: linux-parisc@vger.kernel.org
> > > > 
> > > > On 2021-02-19, John Ogness <john.ogness@linutronix.de> wrote:
> > > > > > > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> > > > > > > index 20c21a25143d..401df370832b 100644
> > > > > > > --- a/kernel/printk/printk.c
> > > > > > > +++ b/kernel/printk/printk.c
> > > > > > > +/* Return a consistent copy of @syslog_seq. */
> > > > > > > +static u64 read_syslog_seq_irq(void)
> > > > > > > +{
> > > > > > > +	u64 seq;
> > > > > > > +
> > > > > > > +	raw_spin_lock_irq(&syslog_lock);
> > > > > > > +	seq = syslog_seq;
> > > > > > > +	raw_spin_unlock_irq(&syslog_lock);
> > > > > > 
> > > > > > Is there any particular reason to disable interrupts here?
> > > > > > 
> > > > I found a possible call chain in interrupt context. From arch/parisc
> > > > there is the interrupt handler:
> > > > 
> > > Yes, handle_interruption() is the irq handler, running with irqs off.
> > > HPMC is the crash handler - it's called when the kernel will stop
> > > anyway. pdc_console is a very basic firmware console which prints
> > > the last messages before the machine halts on fatal errors.
> > > So, this code it's not the typical use case....
> > 
> > Thanks for information.
> > 
> > Is this code supposed to work only during early boot or anytime,
> > please?
> 
> No.
> It's only called when the kernel completely crashes, when all
> spinlocks should get busted and so on.
> It's the emergency way to get some info out at least.

OK.

> > Note that it is not safe because register_console() takes
> > console_lock() which is a sleeping lock.
> 
> As I said, in that stage the plan is to bust all spinlocks.

Just to be sure. Note that that register_console() does not bust
console_lock in panic.

bust_spinlocks() just increments oops_in_progress counter. It has
effect only when the caller checks this variable and use trylock
when it is set. For example, see serial8250_console_write():

void serial8250_console_write(struct uart_8250_port *up, const char *s,
			      unsigned int count)
{
	int locked = 1;

	if (oops_in_progress)
		locked = spin_trylock_irqsave(&port->lock, flags);
	else
		spin_lock_irqsave(&port->lock, flags);


	...


	if (locked)
		spin_unlock_irqrestore(&port->lock, flags);
}

register_console() does not check oops_in_progress at the moment
and might get blocked on console_sem.

We could add the checks for oops_in_progress into register_console().
But I am not sure if it is worth it. It seems that you used this code
for ages. The risk of the deadlock is small. It likely works most
of the time. The upcoming printk rework should allow a cleaner
solution.

Best Regards,
Petr

Re: [PATCH printk-rework 08/14] printk: add syslog_lock

[Helge Deller]

On 2/23/21 3:23 PM, Petr Mladek wrote:
> On Tue 2021-02-23 13:22:22, Helge Deller wrote:
>> On 2/22/21 5:28 PM, Petr Mladek wrote:
>>> On Sun 2021-02-21 22:39:42, Helge Deller wrote:
>>>> On 2/19/21 5:33 PM, John Ogness wrote:
>>>>> Added CC: linux-parisc@vger.kernel.org
>>>>>
>>>>> On 2021-02-19, John Ogness <john.ogness@linutronix.de> wrote:
>>>>>>>> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
>>>>>>>> index 20c21a25143d..401df370832b 100644
>>>>>>>> --- a/kernel/printk/printk.c
>>>>>>>> +++ b/kernel/printk/printk.c
>>>>>>>> +/* Return a consistent copy of @syslog_seq. */
>>>>>>>> +static u64 read_syslog_seq_irq(void)
>>>>>>>> +{
>>>>>>>> +	u64 seq;
>>>>>>>> +
>>>>>>>> +	raw_spin_lock_irq(&syslog_lock);
>>>>>>>> +	seq = syslog_seq;
>>>>>>>> +	raw_spin_unlock_irq(&syslog_lock);
>>>>>>>
>>>>>>> Is there any particular reason to disable interrupts here?
>>>>>>>
>>>>> I found a possible call chain in interrupt context. From arch/parisc
>>>>> there is the interrupt handler:
>>>>>
>>>> Yes, handle_interruption() is the irq handler, running with irqs off.
>>>> HPMC is the crash handler - it's called when the kernel will stop
>>>> anyway. pdc_console is a very basic firmware console which prints
>>>> the last messages before the machine halts on fatal errors.
>>>> So, this code it's not the typical use case....
>>>
>>> Thanks for information.
>>>
>>> Is this code supposed to work only during early boot or anytime,
>>> please?
>>
>> No.
>> It's only called when the kernel completely crashes, when all
>> spinlocks should get busted and so on.
>> It's the emergency way to get some info out at least.
>
> OK.
>
>>> Note that it is not safe because register_console() takes
>>> console_lock() which is a sleeping lock.
>>
>> As I said, in that stage the plan is to bust all spinlocks.
>
> Just to be sure. Note that that register_console() does not bust
> console_lock in panic.

Ok.

> bust_spinlocks() just increments oops_in_progress counter. It has
> effect only when the caller checks this variable and use trylock
> when it is set. For example, see serial8250_console_write():
>
> void serial8250_console_write(struct uart_8250_port *up, const char *s,
> 			      unsigned int count)
> {
> 	int locked = 1;
>
> 	if (oops_in_progress)
> 		locked = spin_trylock_irqsave(&port->lock, flags);
> 	else
> 		spin_lock_irqsave(&port->lock, flags);
>
>
> 	...
>
>
> 	if (locked)
> 		spin_unlock_irqrestore(&port->lock, flags);
> }
>
> register_console() does not check oops_in_progress at the moment
> and might get blocked on console_sem.
>
> We could add the checks for oops_in_progress into register_console().
> But I am not sure if it is worth it.

It's not worth it just because of parisc.
I haven't seen any such crash in years, so the current implementation
is probably untested and outdated.

> It seems that you used this code for ages. The risk of the deadlock
> is small. It likely works most of the time. The upcoming printk rework
> should allow a cleaner solution.

Yes, it would be great if you can include such a "hard-panic/crash-dump-case"
in the rework.

Helge

Re: [PATCH printk-rework 08/14] printk: add syslog_lock

[Petr Mladek]

On Fri 2021-02-19 15:45:21, John Ogness wrote:
> On 2021-02-19, Petr Mladek <pmladek@suse.com> wrote:
> >> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> >> index 20c21a25143d..401df370832b 100644
> >> --- a/kernel/printk/printk.c
> >> +++ b/kernel/printk/printk.c
> >> +/* Return a consistent copy of @syslog_seq. */
> >> +static u64 read_syslog_seq_irq(void)
> >> +{
> >> +	u64 seq;
> >> +
> >> +	raw_spin_lock_irq(&syslog_lock);
> >> +	seq = syslog_seq;
> >> +	raw_spin_unlock_irq(&syslog_lock);
> >
> > Is there any particular reason to disable interrupts here?
> >
> > It would make sense only when the lock could be taken in IRQ
> > context. Then we would need to always disable interrupts when
> > the lock is taken. And if it is taken in IRQ context, we would
> > need to safe flags.
> 
> All other instances of locking @syslog_lock are done with interrupts
> disabled. And we have:
> 
> register_console()
>   logbuf_lock_irqsave()
>     raw_spin_lock(&syslog_lock)

I see. We should revisit this after removing logbuf_lock and
printk_safe context.

> Looking back through history, I found that locking of the "console lock"
> in register_console() was changed from spin_lock_irq() to
> spin_lock_irqsave() for 2.3.15pre1 [0]. The only reason I can find why
> that was done is because sparc64 was regstering its console in a PROM
> callback (the comments there: "Pretty sick eh?").

Note that console_lock was a spinlock in 2.3.15.pre1. I see it defined
in kernel/printk.c as:

spinlock_t console_lock = SPIN_LOCK_UNLOCKED;

But it is a sleeping semaphore these days. As a result,
register_console(), as it is now, must not be called in an interrupt context.

Best Regards,
Petr

Re: [PATCH printk-rework 08/14] printk: add syslog_lock

[John Ogness]

On 2021-02-22, Petr Mladek <pmladek@suse.com> wrote:
>>>> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
>>>> index 20c21a25143d..401df370832b 100644
>>>> --- a/kernel/printk/printk.c
>>>> +++ b/kernel/printk/printk.c
>>>> +/* Return a consistent copy of @syslog_seq. */
>>>> +static u64 read_syslog_seq_irq(void)
>>>> +{
>>>> +	u64 seq;
>>>> +
>>>> +	raw_spin_lock_irq(&syslog_lock);
>>>> +	seq = syslog_seq;
>>>> +	raw_spin_unlock_irq(&syslog_lock);
>>>
>>> Is there any particular reason to disable interrupts here?
>>>
>>> It would make sense only when the lock could be taken in IRQ
>>> context. Then we would need to always disable interrupts when
>>> the lock is taken. And if it is taken in IRQ context, we would
>>> need to safe flags.
>
> Note that console_lock was a spinlock in 2.3.15.pre1. I see it defined
> in kernel/printk.c as:
>
> spinlock_t console_lock = SPIN_LOCK_UNLOCKED;
>
> But it is a sleeping semaphore these days. As a result,
> register_console(), as it is now, must not be called in an interrupt
> context.

OK. So I will change read_syslog_seq_irq() to not disable interrupts. As
you suggested, we can fix the rest when we remove the safe buffers.

John Ogness

Re: [PATCH printk-rework 08/14] printk: add syslog_lock

[Petr Mladek]

On Mon 2021-02-22 17:43:56, John Ogness wrote:
> On 2021-02-22, Petr Mladek <pmladek@suse.com> wrote:
> >>>> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> >>>> index 20c21a25143d..401df370832b 100644
> >>>> --- a/kernel/printk/printk.c
> >>>> +++ b/kernel/printk/printk.c
> >>>> +/* Return a consistent copy of @syslog_seq. */
> >>>> +static u64 read_syslog_seq_irq(void)
> >>>> +{
> >>>> +	u64 seq;
> >>>> +
> >>>> +	raw_spin_lock_irq(&syslog_lock);
> >>>> +	seq = syslog_seq;
> >>>> +	raw_spin_unlock_irq(&syslog_lock);
> >>>
> >>> Is there any particular reason to disable interrupts here?
> >>>
> >>> It would make sense only when the lock could be taken in IRQ
> >>> context. Then we would need to always disable interrupts when
> >>> the lock is taken. And if it is taken in IRQ context, we would
> >>> need to safe flags.
> >
> > Note that console_lock was a spinlock in 2.3.15.pre1. I see it defined
> > in kernel/printk.c as:
> >
> > spinlock_t console_lock = SPIN_LOCK_UNLOCKED;
> >
> > But it is a sleeping semaphore these days. As a result,
> > register_console(), as it is now, must not be called in an interrupt
> > context.
> 
> OK. So I will change read_syslog_seq_irq() to not disable interrupts. As
> you suggested, we can fix the rest when we remove the safe buffers.

I do not have strong opinion any longer. The disabled interrupts
should not change anything, except theoretically for the parisc
emergency console.

Maybe keep the disabled interrupts there until we have a better solution
for parisc.

Best Regards,
Petr

[PATCH printk-rework 09/14] printk: introduce a kmsg_dump iterator

[John Ogness]

Rather than store the iterator information into the registered
kmsg_dump structure, create a separate iterator structure. The
kmsg_dump_iter structure can reside on the stack of the caller,
thus allowing lockless use of the kmsg_dump functions.

This is in preparation for removal of @logbuf_lock.

Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
 arch/powerpc/kernel/nvram_64.c             | 12 ++--
 arch/powerpc/platforms/powernv/opal-kmsg.c |  3 +-
 arch/powerpc/xmon/xmon.c                   |  6 +-
 arch/um/kernel/kmsg_dump.c                 |  5 +-
 drivers/hv/vmbus_drv.c                     |  5 +-
 drivers/mtd/mtdoops.c                      |  5 +-
 fs/pstore/platform.c                       |  5 +-
 include/linux/kmsg_dump.h                  | 43 +++++++-------
 kernel/debug/kdb/kdb_main.c                | 10 ++--
 kernel/printk/printk.c                     | 65 +++++++++++-----------
 10 files changed, 84 insertions(+), 75 deletions(-)

diff --git a/arch/powerpc/kernel/nvram_64.c b/arch/powerpc/kernel/nvram_64.c
index 532f22637783..1ef55f4b389a 100644
--- a/arch/powerpc/kernel/nvram_64.c
+++ b/arch/powerpc/kernel/nvram_64.c
@@ -73,7 +73,8 @@ static const char *nvram_os_partitions[] = {
 };
 
 static void oops_to_nvram(struct kmsg_dumper *dumper,
-			  enum kmsg_dump_reason reason);
+			  enum kmsg_dump_reason reason,
+			  struct kmsg_dumper_iter *iter);
 
 static struct kmsg_dumper nvram_kmsg_dumper = {
 	.dump = oops_to_nvram
@@ -643,7 +644,8 @@ void __init nvram_init_oops_partition(int rtas_partition_exists)
  * partition.  If that's too much, go back and capture uncompressed text.
  */
 static void oops_to_nvram(struct kmsg_dumper *dumper,
-			  enum kmsg_dump_reason reason)
+			  enum kmsg_dump_reason reason,
+			  struct kmsg_dumper_iter *iter)
 {
 	struct oops_log_info *oops_hdr = (struct oops_log_info *)oops_buf;
 	static unsigned int oops_count = 0;
@@ -681,13 +683,13 @@ static void oops_to_nvram(struct kmsg_dumper *dumper,
 		return;
 
 	if (big_oops_buf) {
-		kmsg_dump_get_buffer(dumper, false,
+		kmsg_dump_get_buffer(iter, false,
 				     big_oops_buf, big_oops_buf_sz, &text_len);
 		rc = zip_oops(text_len);
 	}
 	if (rc != 0) {
-		kmsg_dump_rewind(dumper);
-		kmsg_dump_get_buffer(dumper, false,
+		kmsg_dump_rewind(iter);
+		kmsg_dump_get_buffer(iter, false,
 				     oops_data, oops_data_sz, &text_len);
 		err_type = ERR_TYPE_KERNEL_PANIC;
 		oops_hdr->version = cpu_to_be16(OOPS_HDR_VERSION);
diff --git a/arch/powerpc/platforms/powernv/opal-kmsg.c b/arch/powerpc/platforms/powernv/opal-kmsg.c
index 6c3bc4b4da98..ec862846bc82 100644
--- a/arch/powerpc/platforms/powernv/opal-kmsg.c
+++ b/arch/powerpc/platforms/powernv/opal-kmsg.c
@@ -20,7 +20,8 @@
  * message, it just ensures that OPAL completely flushes the console buffer.
  */
 static void kmsg_dump_opal_console_flush(struct kmsg_dumper *dumper,
-				     enum kmsg_dump_reason reason)
+					 enum kmsg_dump_reason reason,
+					 struct kmsg_dumper_iter *iter)
 {
 	/*
 	 * Outside of a panic context the pollers will continue to run,
diff --git a/arch/powerpc/xmon/xmon.c b/arch/powerpc/xmon/xmon.c
index 55c43a6c9111..43162b885259 100644
--- a/arch/powerpc/xmon/xmon.c
+++ b/arch/powerpc/xmon/xmon.c
@@ -3003,7 +3003,7 @@ print_address(unsigned long addr)
 static void
 dump_log_buf(void)
 {
-	struct kmsg_dumper dumper = { .active = 1 };
+	struct kmsg_dumper_iter iter = { .active = 1 };
 	unsigned char buf[128];
 	size_t len;
 
@@ -3015,9 +3015,9 @@ dump_log_buf(void)
 	catch_memory_errors = 1;
 	sync();
 
-	kmsg_dump_rewind_nolock(&dumper);
+	kmsg_dump_rewind_nolock(&iter);
 	xmon_start_pagination();
-	while (kmsg_dump_get_line_nolock(&dumper, false, buf, sizeof(buf), &len)) {
+	while (kmsg_dump_get_line_nolock(&iter, false, buf, sizeof(buf), &len)) {
 		buf[len] = '\0';
 		printf("%s", buf);
 	}
diff --git a/arch/um/kernel/kmsg_dump.c b/arch/um/kernel/kmsg_dump.c
index e4abac6c9727..f38349ad00ea 100644
--- a/arch/um/kernel/kmsg_dump.c
+++ b/arch/um/kernel/kmsg_dump.c
@@ -6,7 +6,8 @@
 #include <os.h>
 
 static void kmsg_dumper_stdout(struct kmsg_dumper *dumper,
-				enum kmsg_dump_reason reason)
+				enum kmsg_dump_reason reason,
+				struct kmsg_dumper_iter *iter)
 {
 	static char line[1024];
 	struct console *con;
@@ -25,7 +26,7 @@ static void kmsg_dumper_stdout(struct kmsg_dumper *dumper,
 		return;
 
 	printf("kmsg_dump:\n");
-	while (kmsg_dump_get_line(dumper, true, line, sizeof(line), &len)) {
+	while (kmsg_dump_get_line(iter, true, line, sizeof(line), &len)) {
 		line[len] = '\0';
 		printf("%s", line);
 	}
diff --git a/drivers/hv/vmbus_drv.c b/drivers/hv/vmbus_drv.c
index 4fad3e6745e5..fbeddef90941 100644
--- a/drivers/hv/vmbus_drv.c
+++ b/drivers/hv/vmbus_drv.c
@@ -1359,7 +1359,8 @@ static void vmbus_isr(void)
  * buffer and call into Hyper-V to transfer the data.
  */
 static void hv_kmsg_dump(struct kmsg_dumper *dumper,
-			 enum kmsg_dump_reason reason)
+			 enum kmsg_dump_reason reason,
+			 struct kmsg_dumper_iter *iter)
 {
 	size_t bytes_written;
 	phys_addr_t panic_pa;
@@ -1374,7 +1375,7 @@ static void hv_kmsg_dump(struct kmsg_dumper *dumper,
 	 * Write dump contents to the page. No need to synchronize; panic should
 	 * be single-threaded.
 	 */
-	kmsg_dump_get_buffer(dumper, false, hv_panic_page, HV_HYP_PAGE_SIZE,
+	kmsg_dump_get_buffer(iter, false, hv_panic_page, HV_HYP_PAGE_SIZE,
 			     &bytes_written);
 	if (bytes_written)
 		hyperv_report_panic_msg(panic_pa, bytes_written);
diff --git a/drivers/mtd/mtdoops.c b/drivers/mtd/mtdoops.c
index 774970bfcf85..6bc2c728adb7 100644
--- a/drivers/mtd/mtdoops.c
+++ b/drivers/mtd/mtdoops.c
@@ -267,7 +267,8 @@ static void find_next_position(struct mtdoops_context *cxt)
 }
 
 static void mtdoops_do_dump(struct kmsg_dumper *dumper,
-			    enum kmsg_dump_reason reason)
+			    enum kmsg_dump_reason reason,
+			    struct kmsg_dumper_iter *iter)
 {
 	struct mtdoops_context *cxt = container_of(dumper,
 			struct mtdoops_context, dump);
@@ -276,7 +277,7 @@ static void mtdoops_do_dump(struct kmsg_dumper *dumper,
 	if (reason == KMSG_DUMP_OOPS && !dump_oops)
 		return;
 
-	kmsg_dump_get_buffer(dumper, true, cxt->oops_buf + MTDOOPS_HEADER_SIZE,
+	kmsg_dump_get_buffer(iter, true, cxt->oops_buf + MTDOOPS_HEADER_SIZE,
 			     record_size - MTDOOPS_HEADER_SIZE, NULL);
 
 	if (reason != KMSG_DUMP_OOPS) {
diff --git a/fs/pstore/platform.c b/fs/pstore/platform.c
index 36714df37d5d..a939559b0c9a 100644
--- a/fs/pstore/platform.c
+++ b/fs/pstore/platform.c
@@ -383,7 +383,8 @@ void pstore_record_init(struct pstore_record *record,
  * end of the buffer.
  */
 static void pstore_dump(struct kmsg_dumper *dumper,
-			enum kmsg_dump_reason reason)
+			enum kmsg_dump_reason reason,
+			struct kmsg_dumper_iter *iter)
 {
 	unsigned long	total = 0;
 	const char	*why;
@@ -435,7 +436,7 @@ static void pstore_dump(struct kmsg_dumper *dumper,
 		dst_size -= header_size;
 
 		/* Write dump contents. */
-		if (!kmsg_dump_get_buffer(dumper, true, dst + header_size,
+		if (!kmsg_dump_get_buffer(iter, true, dst + header_size,
 					  dst_size, &dump_size))
 			break;
 
diff --git a/include/linux/kmsg_dump.h b/include/linux/kmsg_dump.h
index 4095a34db0fa..2fdb10ab1799 100644
--- a/include/linux/kmsg_dump.h
+++ b/include/linux/kmsg_dump.h
@@ -29,6 +29,18 @@ enum kmsg_dump_reason {
 	KMSG_DUMP_MAX
 };
 
+/**
+ * struct kmsg_dumper_iter - iterator for kernel crash message dumper
+ * @active:	Flag that specifies if this is currently dumping
+ * @cur_seq:	Points to the oldest message to dump (private)
+ * @next_seq:	Points after the newest message to dump (private)
+ */
+struct kmsg_dumper_iter {
+	bool	active;
+	u64	cur_seq;
+	u64	next_seq;
+};
+
 /**
  * struct kmsg_dumper - kernel crash message dumper structure
  * @list:	Entry in the dumper list (private)
@@ -36,37 +48,30 @@ enum kmsg_dump_reason {
  * 		through the record iterator
  * @max_reason:	filter for highest reason number that should be dumped
  * @registered:	Flag that specifies if this is already registered
- * @active:	Flag that specifies if this is currently dumping
- * @cur_seq:	Points to the oldest message to dump (private)
- * @next_seq:	Points after the newest message to dump (private)
  */
 struct kmsg_dumper {
 	struct list_head list;
-	void (*dump)(struct kmsg_dumper *dumper, enum kmsg_dump_reason reason);
+	void (*dump)(struct kmsg_dumper *dumper, enum kmsg_dump_reason reason,
+		     struct kmsg_dumper_iter *iter);
 	enum kmsg_dump_reason max_reason;
-	bool active;
 	bool registered;
-
-	/* private state of the kmsg iterator */
-	u64 cur_seq;
-	u64 next_seq;
 };
 
 #ifdef CONFIG_PRINTK
 void kmsg_dump(enum kmsg_dump_reason reason);
 
-bool kmsg_dump_get_line_nolock(struct kmsg_dumper *dumper, bool syslog,
+bool kmsg_dump_get_line_nolock(struct kmsg_dumper_iter *iter, bool syslog,
 			       char *line, size_t size, size_t *len);
 
-bool kmsg_dump_get_line(struct kmsg_dumper *dumper, bool syslog,
+bool kmsg_dump_get_line(struct kmsg_dumper_iter *iter, bool syslog,
 			char *line, size_t size, size_t *len);
 
-bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
+bool kmsg_dump_get_buffer(struct kmsg_dumper_iter *iter, bool syslog,
 			  char *buf, size_t size, size_t *len_out);
 
-void kmsg_dump_rewind_nolock(struct kmsg_dumper *dumper);
+void kmsg_dump_rewind_nolock(struct kmsg_dumper_iter *iter);
 
-void kmsg_dump_rewind(struct kmsg_dumper *dumper);
+void kmsg_dump_rewind(struct kmsg_dumper_iter *dumper_iter);
 
 int kmsg_dump_register(struct kmsg_dumper *dumper);
 
@@ -78,30 +83,30 @@ static inline void kmsg_dump(enum kmsg_dump_reason reason)
 {
 }
 
-static inline bool kmsg_dump_get_line_nolock(struct kmsg_dumper *dumper,
+static inline bool kmsg_dump_get_line_nolock(struct kmsg_dumper_iter *iter,
 					     bool syslog, const char *line,
 					     size_t size, size_t *len)
 {
 	return false;
 }
 
-static inline bool kmsg_dump_get_line(struct kmsg_dumper *dumper, bool syslog,
+static inline bool kmsg_dump_get_line(struct kmsg_dumper_iter *iter, bool syslog,
 				const char *line, size_t size, size_t *len)
 {
 	return false;
 }
 
-static inline bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
+static inline bool kmsg_dump_get_buffer(struct kmsg_dumper_iter *iter, bool syslog,
 					char *buf, size_t size, size_t *len)
 {
 	return false;
 }
 
-static inline void kmsg_dump_rewind_nolock(struct kmsg_dumper *dumper)
+static inline void kmsg_dump_rewind_nolock(struct kmsg_dumper_iter *iter)
 {
 }
 
-static inline void kmsg_dump_rewind(struct kmsg_dumper *dumper)
+static inline void kmsg_dump_rewind(struct kmsg_dumper_iter *iter)
 {
 }
 
diff --git a/kernel/debug/kdb/kdb_main.c b/kernel/debug/kdb/kdb_main.c
index 930ac1b25ec7..7ae9da245e4b 100644
--- a/kernel/debug/kdb/kdb_main.c
+++ b/kernel/debug/kdb/kdb_main.c
@@ -2101,7 +2101,7 @@ static int kdb_dmesg(int argc, const char **argv)
 	int adjust = 0;
 	int n = 0;
 	int skip = 0;
-	struct kmsg_dumper dumper = { .active = 1 };
+	struct kmsg_dumper_iter iter = { .active = 1 };
 	size_t len;
 	char buf[201];
 
@@ -2126,8 +2126,8 @@ static int kdb_dmesg(int argc, const char **argv)
 		kdb_set(2, setargs);
 	}
 
-	kmsg_dump_rewind_nolock(&dumper);
-	while (kmsg_dump_get_line_nolock(&dumper, 1, NULL, 0, NULL))
+	kmsg_dump_rewind_nolock(&iter);
+	while (kmsg_dump_get_line_nolock(&iter, 1, NULL, 0, NULL))
 		n++;
 
 	if (lines < 0) {
@@ -2159,8 +2159,8 @@ static int kdb_dmesg(int argc, const char **argv)
 	if (skip >= n || skip < 0)
 		return 0;
 
-	kmsg_dump_rewind_nolock(&dumper);
-	while (kmsg_dump_get_line_nolock(&dumper, 1, buf, sizeof(buf), &len)) {
+	kmsg_dump_rewind_nolock(&iter);
+	while (kmsg_dump_get_line_nolock(&iter, 1, buf, sizeof(buf), &len)) {
 		if (skip) {
 			skip--;
 			continue;
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 401df370832b..3ad1f9bcaaa1 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -3385,6 +3385,7 @@ EXPORT_SYMBOL_GPL(kmsg_dump_reason_str);
  */
 void kmsg_dump(enum kmsg_dump_reason reason)
 {
+	struct kmsg_dumper_iter iter;
 	struct kmsg_dumper *dumper;
 	unsigned long flags;
 
@@ -3404,25 +3405,21 @@ void kmsg_dump(enum kmsg_dump_reason reason)
 			continue;
 
 		/* initialize iterator with data about the stored records */
-		dumper->active = true;
-
+		iter.active = true;
 		logbuf_lock_irqsave(flags);
-		dumper->cur_seq = latched_seq_read_nolock(&clear_seq);
-		dumper->next_seq = prb_next_seq(prb);
+		iter.cur_seq = latched_seq_read_nolock(&clear_seq);
+		iter.next_seq = prb_next_seq(prb);
 		logbuf_unlock_irqrestore(flags);
 
 		/* invoke dumper which will iterate over records */
-		dumper->dump(dumper, reason);
-
-		/* reset iterator */
-		dumper->active = false;
+		dumper->dump(dumper, reason, &iter);
 	}
 	rcu_read_unlock();
 }
 
 /**
  * kmsg_dump_get_line_nolock - retrieve one kmsg log line (unlocked version)
- * @dumper: registered kmsg dumper
+ * @iter: kmsg dumper iterator
  * @syslog: include the "<4>" prefixes
  * @line: buffer to copy the line to
  * @size: maximum size of the buffer
@@ -3439,7 +3436,7 @@ void kmsg_dump(enum kmsg_dump_reason reason)
  *
  * The function is similar to kmsg_dump_get_line(), but grabs no locks.
  */
-bool kmsg_dump_get_line_nolock(struct kmsg_dumper *dumper, bool syslog,
+bool kmsg_dump_get_line_nolock(struct kmsg_dumper_iter *iter, bool syslog,
 			       char *line, size_t size, size_t *len)
 {
 	struct printk_info info;
@@ -3450,16 +3447,16 @@ bool kmsg_dump_get_line_nolock(struct kmsg_dumper *dumper, bool syslog,
 
 	prb_rec_init_rd(&r, &info, line, size);
 
-	if (!dumper->active)
+	if (!iter->active)
 		goto out;
 
 	/* Read text or count text lines? */
 	if (line) {
-		if (!prb_read_valid(prb, dumper->cur_seq, &r))
+		if (!prb_read_valid(prb, iter->cur_seq, &r))
 			goto out;
 		l = record_print_text(&r, syslog, printk_time);
 	} else {
-		if (!prb_read_valid_info(prb, dumper->cur_seq,
+		if (!prb_read_valid_info(prb, iter->cur_seq,
 					 &info, &line_count)) {
 			goto out;
 		}
@@ -3468,7 +3465,7 @@ bool kmsg_dump_get_line_nolock(struct kmsg_dumper *dumper, bool syslog,
 
 	}
 
-	dumper->cur_seq = r.info->seq + 1;
+	iter->cur_seq = r.info->seq + 1;
 	ret = true;
 out:
 	if (len)
@@ -3478,7 +3475,7 @@ bool kmsg_dump_get_line_nolock(struct kmsg_dumper *dumper, bool syslog,
 
 /**
  * kmsg_dump_get_line - retrieve one kmsg log line
- * @dumper: registered kmsg dumper
+ * @iter: kmsg dumper iterator
  * @syslog: include the "<4>" prefixes
  * @line: buffer to copy the line to
  * @size: maximum size of the buffer
@@ -3493,14 +3490,14 @@ bool kmsg_dump_get_line_nolock(struct kmsg_dumper *dumper, bool syslog,
  * A return value of FALSE indicates that there are no more records to
  * read.
  */
-bool kmsg_dump_get_line(struct kmsg_dumper *dumper, bool syslog,
+bool kmsg_dump_get_line(struct kmsg_dumper_iter *iter, bool syslog,
 			char *line, size_t size, size_t *len)
 {
 	unsigned long flags;
 	bool ret;
 
 	logbuf_lock_irqsave(flags);
-	ret = kmsg_dump_get_line_nolock(dumper, syslog, line, size, len);
+	ret = kmsg_dump_get_line_nolock(iter, syslog, line, size, len);
 	logbuf_unlock_irqrestore(flags);
 
 	return ret;
@@ -3509,7 +3506,7 @@ EXPORT_SYMBOL_GPL(kmsg_dump_get_line);
 
 /**
  * kmsg_dump_get_buffer - copy kmsg log lines
- * @dumper: registered kmsg dumper
+ * @iter: kmsg dumper iterator
  * @syslog: include the "<4>" prefixes
  * @buf: buffer to copy the line to
  * @size: maximum size of the buffer
@@ -3526,7 +3523,7 @@ EXPORT_SYMBOL_GPL(kmsg_dump_get_line);
  * A return value of FALSE indicates that there are no more records to
  * read.
  */
-bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
+bool kmsg_dump_get_buffer(struct kmsg_dumper_iter *iter, bool syslog,
 			  char *buf, size_t size, size_t *len_out)
 {
 	struct printk_info info;
@@ -3538,19 +3535,19 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
 	bool ret = false;
 	bool time = printk_time;
 
-	if (!dumper->active || !buf || !size)
+	if (!iter->active || !buf || !size)
 		goto out;
 
 	logbuf_lock_irqsave(flags);
-	if (prb_read_valid_info(prb, dumper->cur_seq, &info, NULL)) {
-		if (info.seq != dumper->cur_seq) {
+	if (prb_read_valid_info(prb, iter->cur_seq, &info, NULL)) {
+		if (info.seq != iter->cur_seq) {
 			/* messages are gone, move to first available one */
-			dumper->cur_seq = info.seq;
+			iter->cur_seq = info.seq;
 		}
 	}
 
 	/* last entry */
-	if (dumper->cur_seq >= dumper->next_seq) {
+	if (iter->cur_seq >= iter->next_seq) {
 		logbuf_unlock_irqrestore(flags);
 		goto out;
 	}
@@ -3561,7 +3558,7 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
 	 * because this function (by way of record_print_text()) will
 	 * not write more than size-1 bytes of text into @buf.
 	 */
-	seq = find_first_fitting_seq(dumper->cur_seq, dumper->next_seq,
+	seq = find_first_fitting_seq(iter->cur_seq, iter->next_seq,
 				     size - 1, syslog, time);
 
 	/*
@@ -3574,7 +3571,7 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
 
 	len = 0;
 	prb_for_each_record(seq, prb, seq, &r) {
-		if (r.info->seq >= dumper->next_seq)
+		if (r.info->seq >= iter->next_seq)
 			break;
 
 		len += record_print_text(&r, syslog, time);
@@ -3583,7 +3580,7 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
 		prb_rec_init_rd(&r, &info, buf + len, size - len);
 	}
 
-	dumper->next_seq = next_seq;
+	iter->next_seq = next_seq;
 	ret = true;
 	logbuf_unlock_irqrestore(flags);
 out:
@@ -3595,7 +3592,7 @@ EXPORT_SYMBOL_GPL(kmsg_dump_get_buffer);
 
 /**
  * kmsg_dump_rewind_nolock - reset the iterator (unlocked version)
- * @dumper: registered kmsg dumper
+ * @iter: kmsg dumper iterator
  *
  * Reset the dumper's iterator so that kmsg_dump_get_line() and
  * kmsg_dump_get_buffer() can be called again and used multiple
@@ -3603,26 +3600,26 @@ EXPORT_SYMBOL_GPL(kmsg_dump_get_buffer);
  *
  * The function is similar to kmsg_dump_rewind(), but grabs no locks.
  */
-void kmsg_dump_rewind_nolock(struct kmsg_dumper *dumper)
+void kmsg_dump_rewind_nolock(struct kmsg_dumper_iter *iter)
 {
-	dumper->cur_seq = latched_seq_read_nolock(&clear_seq);
-	dumper->next_seq = prb_next_seq(prb);
+	iter->cur_seq = latched_seq_read_nolock(&clear_seq);
+	iter->next_seq = prb_next_seq(prb);
 }
 
 /**
  * kmsg_dump_rewind - reset the iterator
- * @dumper: registered kmsg dumper
+ * @iter: kmsg dumper iterator
  *
  * Reset the dumper's iterator so that kmsg_dump_get_line() and
  * kmsg_dump_get_buffer() can be called again and used multiple
  * times within the same dumper.dump() callback.
  */
-void kmsg_dump_rewind(struct kmsg_dumper *dumper)
+void kmsg_dump_rewind(struct kmsg_dumper_iter *iter)
 {
 	unsigned long flags;
 
 	logbuf_lock_irqsave(flags);
-	kmsg_dump_rewind_nolock(dumper);
+	kmsg_dump_rewind_nolock(iter);
 	logbuf_unlock_irqrestore(flags);
 }
 EXPORT_SYMBOL_GPL(kmsg_dump_rewind);
-- 
2.20.1

Re: [PATCH printk-rework 09/14] printk: introduce a kmsg_dump iterator

[Petr Mladek]

On Thu 2021-02-18 09:18:12, John Ogness wrote:
> Rather than store the iterator information into the registered

s/store/storing/ ?

> kmsg_dump structure, create a separate iterator structure. The
> kmsg_dump_iter structure can reside on the stack of the caller,
> thus allowing lockless use of the kmsg_dump functions.
> 
> This is in preparation for removal of @logbuf_lock.
> 
> diff --git a/include/linux/kmsg_dump.h b/include/linux/kmsg_dump.h
> index 4095a34db0fa..2fdb10ab1799 100644
> --- a/include/linux/kmsg_dump.h
> +++ b/include/linux/kmsg_dump.h
> @@ -29,6 +29,18 @@ enum kmsg_dump_reason {
>  	KMSG_DUMP_MAX
>  };
>  
> +/**
> + * struct kmsg_dumper_iter - iterator for kernel crash message dumper
> + * @active:	Flag that specifies if this is currently dumping
> + * @cur_seq:	Points to the oldest message to dump (private)
> + * @next_seq:	Points after the newest message to dump (private)

"(private)" might be removed.

Anyway, the issues are only cosmetic:

Reviewed-by: Petr Mladek <pmladek@suse.com>

Best Regards,
Petr

RE: [PATCH printk-rework 09/14] printk: introduce a kmsg_dump iterator

[Michael Kelley]

From: John Ogness <john.ogness@linutronix.de> Sent: Thursday, February 18, 2021 12:18 AM
> 
> Rather than store the iterator information into the registered
> kmsg_dump structure, create a separate iterator structure. The
> kmsg_dump_iter structure can reside on the stack of the caller,
> thus allowing lockless use of the kmsg_dump functions.
> 
> This is in preparation for removal of @logbuf_lock.
> 
> Signed-off-by: John Ogness <john.ogness@linutronix.de>
> ---
>  arch/powerpc/kernel/nvram_64.c             | 12 ++--
>  arch/powerpc/platforms/powernv/opal-kmsg.c |  3 +-
>  arch/powerpc/xmon/xmon.c                   |  6 +-
>  arch/um/kernel/kmsg_dump.c                 |  5 +-
>  drivers/hv/vmbus_drv.c                     |  5 +-
>  drivers/mtd/mtdoops.c                      |  5 +-
>  fs/pstore/platform.c                       |  5 +-
>  include/linux/kmsg_dump.h                  | 43 +++++++-------
>  kernel/debug/kdb/kdb_main.c                | 10 ++--
>  kernel/printk/printk.c                     | 65 +++++++++++-----------
>  10 files changed, 84 insertions(+), 75 deletions(-)
> 

[snip]

> diff --git a/drivers/hv/vmbus_drv.c b/drivers/hv/vmbus_drv.c
> index 4fad3e6745e5..fbeddef90941 100644
> --- a/drivers/hv/vmbus_drv.c
> +++ b/drivers/hv/vmbus_drv.c
> @@ -1359,7 +1359,8 @@ static void vmbus_isr(void)
>   * buffer and call into Hyper-V to transfer the data.
>   */
>  static void hv_kmsg_dump(struct kmsg_dumper *dumper,
> -			 enum kmsg_dump_reason reason)
> +			 enum kmsg_dump_reason reason,
> +			 struct kmsg_dumper_iter *iter)
>  {
>  	size_t bytes_written;
>  	phys_addr_t panic_pa;
> @@ -1374,7 +1375,7 @@ static void hv_kmsg_dump(struct kmsg_dumper *dumper,
>  	 * Write dump contents to the page. No need to synchronize; panic should
>  	 * be single-threaded.
>  	 */
> -	kmsg_dump_get_buffer(dumper, false, hv_panic_page, HV_HYP_PAGE_SIZE,
> +	kmsg_dump_get_buffer(iter, false, hv_panic_page, HV_HYP_PAGE_SIZE,
>  			     &bytes_written);
>  	if (bytes_written)
>  		hyperv_report_panic_msg(panic_pa, bytes_written);

For the Hyper-V portion,

Reviewed-by: Michael Kelley <mikelley@microsoft.com>

synchronization model: was: Re: [PATCH printk-rework 09/14] printk: introduce a kmsg_dump iterator

[Petr Mladek]

On Thu 2021-02-18 09:18:12, John Ogness wrote:
> Rather than store the iterator information into the registered
> kmsg_dump structure, create a separate iterator structure. The
> kmsg_dump_iter structure can reside on the stack of the caller,
> thus allowing lockless use of the kmsg_dump functions.
> 
> This is in preparation for removal of @logbuf_lock.
> 
> diff --git a/include/linux/kmsg_dump.h b/include/linux/kmsg_dump.h
> index 4095a34db0fa..2fdb10ab1799 100644
> --- a/include/linux/kmsg_dump.h
> +++ b/include/linux/kmsg_dump.h
> @@ -29,6 +29,18 @@ enum kmsg_dump_reason {
>  	KMSG_DUMP_MAX
>  };
>  
> +/**
> + * struct kmsg_dumper_iter - iterator for kernel crash message dumper
> + * @active:	Flag that specifies if this is currently dumping
> + * @cur_seq:	Points to the oldest message to dump (private)
> + * @next_seq:	Points after the newest message to dump (private)
> + */
> +struct kmsg_dumper_iter {
> +	bool	active;
> +	u64	cur_seq;
> +	u64	next_seq;
> +};
> +

This is likely beyond the scope of this patchset.

I am still scratching my head about the synchronization if these dumpers.

There is the "active" flag. It has been introduced by the commit
e2ae715d66bf4becfb ("kmsg - kmsg_dump() use iterator to receive log
buffer content"). I do not see any explanation there.

It might prevent some misuse of the API. But the synchronization
model is not much clear:

	+ cur_seq and next_seq might be manipulated by
	  kmsg_dump_rewind() even when the flag is not set.

	+ It is possible to use the same dumper more times in parallel.
	  The API will fill the provided buffer of all callers
	  as long as the active flag is set.

	+ The "active" flag does not synchronize other operations with
	  the provided buffer. The "dump" callback is responsible
	  to provide some synchronization on its own.

In fact, it is not much clear how struct kmsg_dumper_iter, struct kmsg_dumper,
and the used buffers are connected with each other and synchronized.

It might some sense to have the iterator in a separate structure.
But the only safe scenario seems to be when all these three things
(both structures and the buffer) are connected together and
synchronized by the same lock. Also the "active" flag does not look
much helpful and can be removed.

As I said, this is likely beyond this patchset. This patch does more
or less just a refactoring and helps to understand the dependencies.

It is possible that it will be more clear the following week
with a fresh mind.

Best Regards,
Petr

Re: synchronization model: was: Re: [PATCH printk-rework 09/14] printk: introduce a kmsg_dump iterator

[John Ogness]

On 2021-02-19, Petr Mladek <pmladek@suse.com> wrote:
> This is likely beyond the scope of this patchset.

It would be beyond the scope of this patchset because it is not related
to logbuf_lock removal.

> I am still scratching my head about the synchronization if these dumpers.
>
> There is the "active" flag. It has been introduced by the commit
> e2ae715d66bf4becfb ("kmsg - kmsg_dump() use iterator to receive log
> buffer content"). I do not see any explanation there.
>
> It might prevent some misuse of the API. But the synchronization
> model is not much clear:
>
> 	+ cur_seq and next_seq might be manipulated by
> 	  kmsg_dump_rewind() even when the flag is not set.
>
> 	+ It is possible to use the same dumper more times in parallel.
> 	  The API will fill the provided buffer of all callers
> 	  as long as the active flag is set.
>
> 	+ The "active" flag does not synchronize other operations with
> 	  the provided buffer. The "dump" callback is responsible
> 	  to provide some synchronization on its own.
>
> In fact, it is not much clear how struct kmsg_dumper_iter, struct kmsg_dumper,
> and the used buffers are connected with each other and synchronized.

With this series applied, there is no connection between them. And
actually you have made me realize that the iterator should be named
"kmsg_dump_iter" instead. I will change that for v3.

> It might some sense to have the iterator in a separate structure.
> But the only safe scenario seems to be when all these three things
> (both structures and the buffer) are connected together and
> synchronized by the same lock. Also the "active" flag does not look
> much helpful and can be removed.

The @active flag is useless. It should be removed.

We have kmsg_dump_get_line(), kmsg_dump_get_buffer(), kmsg_dump_rewind()
as an in-kernel interface to allow retrieving the kernel buffer
contents. To use these interfaces, the caller only needs to have an
iterator that is initialized using kmsg_dump_rewind(). These functions
can be (and are) used, regardless if a dumper has been registered. And I
think that is OK.

The used buffers (like the iterator) are local to the caller. So there
is no need for the kmsg_dump_*() functions to be concerned about any
synchronization there.

Then we have kmsg_dump_register() and kmsg_dump_unregister() to allow
for registration of a dump() callback, to be called when the kernel does
panic/oops/emergency/shutdown. Presumably the registered callback would
use the kmsg_dump_*() functions to access the kernel buffer. Again, no
need for kmsg_dump_*() functions to be concerned about synchronization
because the buffers are provided by the callbacks.

> As I said, this is likely beyond this patchset. This patch does more
> or less just a refactoring and helps to understand the dependencies.

Aside from removing the useless @active flag, I am not sure what else
you would want to change. Perhaps just fixup the comments/documentation
to clarify these interfaces and what their purpose is.

John Ogness

Re: synchronization model: was: Re: [PATCH printk-rework 09/14] printk: introduce a kmsg_dump iterator

[John Ogness]

On 2021-02-24, John Ogness <john.ogness@linutronix.de> wrote:
> The @active flag is useless. It should be removed.

I would like to clarify my statement, because the @active flag _did_
protect the arch/um dumper until now. (Although it didn't actually
matter because arch/um does not have SMP or preemption support.)

In mainline we have 6 dumpers. They can be classified as follows:

1. Dumpers that provide their own synchronization to protect against
   parallel or nested dump() calls.

   - arch/powerpc/kernel/nvram_64.c
   - fs/pstore/platform.c
   - arch/um/kernel/kmsg_dump.c (after this series)

2. Dumpers that are safe because they only dump on KMSG_DUMP_PANIC,
   which (currently) can never happen in parallel or nested.

   - arch/powerpc/platforms/powernv/opal-kmsg.c
   - drivers/hv/vmbus_drv.c

3. Dumpers that are unsafe and even @active did not provide the needed
   synchronization.

   - drivers/mtd/mtdoops.c

In all 6 dumpers, @action does not provide any help. That is why it can
be removed.

But I am concerned about drivers/mtd/mtdoops.c that does not have any
synchronization. Since my series is adding sychronization to
arch/um/kernel/kmsg_dump.c, I suppose it should also add it to
drivers/mtd/mtdoops.c also.

And rather than moving the useless @active from kmsg_dumper to
kmsg_dump_iter, I should just drop it.

Unless there are any objections, I will make these changes for my v3.

John Ogness

Re: synchronization model: was: Re: [PATCH printk-rework 09/14] printk: introduce a kmsg_dump iterator

[Petr Mladek]

On Wed 2021-02-24 13:27:42, John Ogness wrote:
> On 2021-02-19, Petr Mladek <pmladek@suse.com> wrote:
> > This is likely beyond the scope of this patchset.
> 
> It would be beyond the scope of this patchset because it is not related
> to logbuf_lock removal.
> 
> > I am still scratching my head about the synchronization if these dumpers.
> >
> > There is the "active" flag. It has been introduced by the commit
> > e2ae715d66bf4becfb ("kmsg - kmsg_dump() use iterator to receive log
> > buffer content"). I do not see any explanation there.
> >
> > It might prevent some misuse of the API. But the synchronization
> > model is not much clear:
> >
> > 	+ cur_seq and next_seq might be manipulated by
> > 	  kmsg_dump_rewind() even when the flag is not set.
> >
> > 	+ It is possible to use the same dumper more times in parallel.
> > 	  The API will fill the provided buffer of all callers
> > 	  as long as the active flag is set.
> >
> > 	+ The "active" flag does not synchronize other operations with
> > 	  the provided buffer. The "dump" callback is responsible
> > 	  to provide some synchronization on its own.
> >
> > In fact, it is not much clear how struct kmsg_dumper_iter, struct kmsg_dumper,
> > and the used buffers are connected with each other and synchronized.
> 
> With this series applied, there is no connection between them. And
> actually you have made me realize that the iterator should be named
> "kmsg_dump_iter" instead. I will change that for v3.

Yup.

> > It might some sense to have the iterator in a separate structure.
> > But the only safe scenario seems to be when all these three things
> > (both structures and the buffer) are connected together and
> > synchronized by the same lock. Also the "active" flag does not look
> > much helpful and can be removed.
> 
> The @active flag is useless. It should be removed.
> 
> We have kmsg_dump_get_line(), kmsg_dump_get_buffer(), kmsg_dump_rewind()
> as an in-kernel interface to allow retrieving the kernel buffer
> contents. To use these interfaces, the caller only needs to have an
> iterator that is initialized using kmsg_dump_rewind(). These functions
> can be (and are) used, regardless if a dumper has been registered. And I
> think that is OK.
> 
> The used buffers (like the iterator) are local to the caller. So there
> is no need for the kmsg_dump_*() functions to be concerned about any
> synchronization there.

Yup, this use-case looks straightforward.

> Then we have kmsg_dump_register() and kmsg_dump_unregister() to allow
> for registration of a dump() callback, to be called when the kernel does
> panic/oops/emergency/shutdown. Presumably the registered callback would
> use the kmsg_dump_*() functions to access the kernel buffer. Again, no
> need for kmsg_dump_*() functions to be concerned about synchronization
> because the buffers are provided by the callbacks.

This is the scenario where the synchronization/logic looks weird to
me. I am not sure if I am able to describe is reasonably. Let me try:

1. The dump is triggered by kmsg_dump(). It is called in several
   code paths like panic/oops/emergency/shutdown. I am not completely
   sure if kmsg_dump() might be called more times in parallel.

   IMHO, it might be, for example, when Oops does not trigger panic
   immediately but the panic() happens in the middle of kmsg_dump()
   triggered by Oops. panic() will then trigger another kmsg_dump()
   that might run in parallel.

2. The iterator struct is provided by kmsg_dump() but the buffers
   are provided by the registered dumper->dump() callback.

3. dumper->dump() callback triggers reading the messages into
   the temporary buffers. But the buffers might later be proceed
   asynchronously, like for example, schedule_work(&cxt->work_write)
   in mtdoops_do_dump().


Now, the split of the iterator struct made it more safe. It allows
to iterate the log buffer more times in parallel. But the buffers
are likely the same even when there are more iterators.

IMHO, a better design would be:

1. dumper->dump() callback should have only one parameter @reason.
   The callback should define its own iterator, buffer, and
   do the dump.

2. dumpe->dump() callback should synchronize the entire operation
   using its own locks. Only the callback knows whether it is
   safe to do more dumps in parallel. Only the callback knows
   whether it is called only during panic() when no locks
   are needed.


> > As I said, this is likely beyond this patchset. This patch does more
> > or less just a refactoring and helps to understand the dependencies.
> 
> Aside from removing the useless @active flag, I am not sure what else
> you would want to change. Perhaps just fixup the comments/documentation
> to clarify these interfaces and what their purpose is.

IMHO, the best solution would be to use the above better design.
But I do not want to ask you to do it as part of the printk rework.
It is an old problem. And this patchset does not make it worse.

I will leave the decision up to you how much you want to invest
here. I could prepare patches for the rest of the clean up
on top of your changes.

Best Regards,
Petr

PS: Your view and the overview of all existing users helped me a lot
    when formulating the above.
    

Re: synchronization model: was: Re: [PATCH printk-rework 09/14] printk: introduce a kmsg_dump iterator

[John Ogness]

On 2021-02-25, Petr Mladek <pmladek@suse.com> wrote:
> IMHO, a better design would be:
>
> 1. dumper->dump() callback should have only one parameter @reason.
>    The callback should define its own iterator, buffer, and
>    do the dump.

Unfortunately this won't work because drivers/mtd/mtdoops.c is using the
dumper parameter for container_of().

So we will need 2 parameters: dumper and reason.

Can we agree to proceed with 2 parameters in the callback?

> 2. dumpe->dump() callback should synchronize the entire operation
>    using its own locks. Only the callback knows whether it is
>    safe to do more dumps in parallel. Only the callback knows
>    whether it is called only during panic() when no locks
>    are needed.

Agreed. I implemented this part for the v3 series.

John Ogness

Re: synchronization model: was: Re: [PATCH printk-rework 09/14] printk: introduce a kmsg_dump iterator

[Petr Mladek]

On Fri 2021-02-26 09:36:21, John Ogness wrote:
> On 2021-02-25, Petr Mladek <pmladek@suse.com> wrote:
> > IMHO, a better design would be:
> >
> > 1. dumper->dump() callback should have only one parameter @reason.
> >    The callback should define its own iterator, buffer, and
> >    do the dump.
> 
> Unfortunately this won't work because drivers/mtd/mtdoops.c is using the
> dumper parameter for container_of().

Ah, I have missed this.

mtdoops code is generic even though everything is static so that there
is always only one instance. But this use case makes sense in general.

> So we will need 2 parameters: dumper and reason.
> 
> Can we agree to proceed with 2 parameters in the callback?

Yup, go for it.

> > 2. dumpe->dump() callback should synchronize the entire operation
> >    using its own locks. Only the callback knows whether it is
> >    safe to do more dumps in parallel. Only the callback knows
> >    whether it is called only during panic() when no locks
> >    are needed.
> 
> Agreed. I implemented this part for the v3 series.

Great!

Best Regards,
Petr

[PATCH printk-rework 10/14] um: synchronize kmsg_dumper

[John Ogness]

The kmsg_dumper can be called from any context and CPU, possibly
from multiple CPUs simultaneously. Since a static buffer is used
to retrieve the kernel logs, this buffer must be protected against
simultaneous dumping.

Cc: Richard Weinberger <richard@nod.at>
Signed-off-by: John Ogness <john.ogness@linutronix.de>
Reviewed-by: Petr Mladek <pmladek@suse.com>
---
 arch/um/kernel/kmsg_dump.c | 8 ++++++++
 1 file changed, 8 insertions(+)

diff --git a/arch/um/kernel/kmsg_dump.c b/arch/um/kernel/kmsg_dump.c
index f38349ad00ea..173999422ed8 100644
--- a/arch/um/kernel/kmsg_dump.c
+++ b/arch/um/kernel/kmsg_dump.c
@@ -1,5 +1,6 @@
 // SPDX-License-Identifier: GPL-2.0
 #include <linux/kmsg_dump.h>
+#include <linux/spinlock.h>
 #include <linux/console.h>
 #include <shared/init.h>
 #include <shared/kern.h>
@@ -9,8 +10,10 @@ static void kmsg_dumper_stdout(struct kmsg_dumper *dumper,
 				enum kmsg_dump_reason reason,
 				struct kmsg_dumper_iter *iter)
 {
+	static DEFINE_SPINLOCK(lock);
 	static char line[1024];
 	struct console *con;
+	unsigned long flags;
 	size_t len = 0;
 
 	/* only dump kmsg when no console is available */
@@ -25,11 +28,16 @@ static void kmsg_dumper_stdout(struct kmsg_dumper *dumper,
 	if (con)
 		return;
 
+	if (!spin_trylock_irqsave(&lock, flags))
+		return;
+
 	printf("kmsg_dump:\n");
 	while (kmsg_dump_get_line(iter, true, line, sizeof(line), &len)) {
 		line[len] = '\0';
 		printf("%s", line);
 	}
+
+	spin_unlock_irqrestore(&lock, flags);
 }
 
 static struct kmsg_dumper kmsg_dumper = {
-- 
2.20.1

[PATCH printk-rework 11/14] printk: remove logbuf_lock

[John Ogness]

Since the ringbuffer is lockless, there is no need for it to be
protected by @logbuf_lock. Remove @logbuf_lock.

This means that printk_nmi_direct and printk_safe_flush_on_panic()
no longer need to acquire any lock to run.

@console_seq, @exclusive_console_stop_seq, @console_dropped are
protected by @console_lock.

Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
 kernel/printk/internal.h    |   4 +-
 kernel/printk/printk.c      | 116 ++++++++++++------------------------
 kernel/printk/printk_safe.c |  29 +++------
 3 files changed, 47 insertions(+), 102 deletions(-)

diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
index 3a8fd491758c..e7acc2888c8e 100644
--- a/kernel/printk/internal.h
+++ b/kernel/printk/internal.h
@@ -12,8 +12,6 @@
 
 #define PRINTK_NMI_CONTEXT_OFFSET	0x010000000
 
-extern raw_spinlock_t logbuf_lock;
-
 __printf(4, 0)
 int vprintk_store(int facility, int level,
 		  const struct dev_printk_info *dev_info,
@@ -59,7 +57,7 @@ void defer_console_output(void);
 __printf(1, 0) int vprintk_func(const char *fmt, va_list args) { return 0; }
 
 /*
- * In !PRINTK builds we still export logbuf_lock spin_lock, console_sem
+ * In !PRINTK builds we still export console_sem
  * semaphore and some of console functions (console_unlock()/etc.), so
  * printk-safe must preserve the existing local IRQ guarantees.
  */
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 3ad1f9bcaaa1..c5ea46ed88c7 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -355,41 +355,6 @@ enum log_flags {
 	LOG_CONT	= 8,	/* text is a fragment of a continuation line */
 };
 
-/*
- * The logbuf_lock protects kmsg buffer, indices, counters.  This can be taken
- * within the scheduler's rq lock. It must be released before calling
- * console_unlock() or anything else that might wake up a process.
- */
-DEFINE_RAW_SPINLOCK(logbuf_lock);
-
-/*
- * Helper macros to lock/unlock logbuf_lock and switch between
- * printk-safe/unsafe modes.
- */
-#define logbuf_lock_irq()				\
-	do {						\
-		printk_safe_enter_irq();		\
-		raw_spin_lock(&logbuf_lock);		\
-	} while (0)
-
-#define logbuf_unlock_irq()				\
-	do {						\
-		raw_spin_unlock(&logbuf_lock);		\
-		printk_safe_exit_irq();			\
-	} while (0)
-
-#define logbuf_lock_irqsave(flags)			\
-	do {						\
-		printk_safe_enter_irqsave(flags);	\
-		raw_spin_lock(&logbuf_lock);		\
-	} while (0)
-
-#define logbuf_unlock_irqrestore(flags)		\
-	do {						\
-		raw_spin_unlock(&logbuf_lock);		\
-		printk_safe_exit_irqrestore(flags);	\
-	} while (0)
-
 /* syslog_lock protects syslog_* variables and write access to clear_seq. */
 static DEFINE_RAW_SPINLOCK(syslog_lock);
 
@@ -401,6 +366,7 @@ static u64 syslog_seq;
 static size_t syslog_partial;
 static bool syslog_time;
 
+/* All 3 protected by @console_sem. */
 /* the next printk record to write to the console */
 static u64 console_seq;
 static u64 exclusive_console_stop_seq;
@@ -767,27 +733,27 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
 	if (ret)
 		return ret;
 
-	logbuf_lock_irq();
+	printk_safe_enter_irq();
 	if (!prb_read_valid(prb, atomic64_read(&user->seq), r)) {
 		if (file->f_flags & O_NONBLOCK) {
 			ret = -EAGAIN;
-			logbuf_unlock_irq();
+			printk_safe_exit_irq();
 			goto out;
 		}
 
-		logbuf_unlock_irq();
+		printk_safe_exit_irq();
 		ret = wait_event_interruptible(log_wait,
 				prb_read_valid(prb, atomic64_read(&user->seq), r));
 		if (ret)
 			goto out;
-		logbuf_lock_irq();
+		printk_safe_enter_irq();
 	}
 
 	if (r->info->seq != atomic64_read(&user->seq)) {
 		/* our last seen message is gone, return error and reset */
 		atomic64_set(&user->seq, r->info->seq);
 		ret = -EPIPE;
-		logbuf_unlock_irq();
+		printk_safe_exit_irq();
 		goto out;
 	}
 
@@ -797,7 +763,7 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
 				  &r->info->dev_info);
 
 	atomic64_set(&user->seq, r->info->seq + 1);
-	logbuf_unlock_irq();
+	printk_safe_exit_irq();
 
 	if (len > count) {
 		ret = -EINVAL;
@@ -832,7 +798,7 @@ static loff_t devkmsg_llseek(struct file *file, loff_t offset, int whence)
 	if (offset)
 		return -ESPIPE;
 
-	logbuf_lock_irq();
+	printk_safe_enter_irq();
 	switch (whence) {
 	case SEEK_SET:
 		/* the first record */
@@ -853,7 +819,7 @@ static loff_t devkmsg_llseek(struct file *file, loff_t offset, int whence)
 	default:
 		ret = -EINVAL;
 	}
-	logbuf_unlock_irq();
+	printk_safe_exit_irq();
 	return ret;
 }
 
@@ -868,7 +834,7 @@ static __poll_t devkmsg_poll(struct file *file, poll_table *wait)
 
 	poll_wait(file, &log_wait, wait);
 
-	logbuf_lock_irq();
+	printk_safe_enter_irq();
 	if (prb_read_valid(prb, atomic64_read(&user->seq), NULL)) {
 		/* return error when data has vanished underneath us */
 		if (info.seq != atomic64_read(&user->seq))
@@ -876,7 +842,7 @@ static __poll_t devkmsg_poll(struct file *file, poll_table *wait)
 		else
 			ret = EPOLLIN|EPOLLRDNORM;
 	}
-	logbuf_unlock_irq();
+	printk_safe_exit_irq();
 
 	return ret;
 }
@@ -909,9 +875,9 @@ static int devkmsg_open(struct inode *inode, struct file *file)
 	prb_rec_init_rd(&user->record, &user->info,
 			&user->text_buf[0], sizeof(user->text_buf));
 
-	logbuf_lock_irq();
+	printk_safe_enter_irq();
 	atomic64_set(&user->seq, prb_first_valid_seq(prb));
-	logbuf_unlock_irq();
+	printk_safe_exit_irq();
 
 	file->private_data = user;
 	return 0;
@@ -1533,11 +1499,11 @@ static int syslog_print(char __user *buf, int size)
 		size_t n;
 		size_t skip;
 
-		logbuf_lock_irq();
+		printk_safe_enter_irq();
 		raw_spin_lock(&syslog_lock);
 		if (!prb_read_valid(prb, syslog_seq, &r)) {
 			raw_spin_unlock(&syslog_lock);
-			logbuf_unlock_irq();
+			printk_safe_exit_irq();
 			break;
 		}
 		if (r.info->seq != syslog_seq) {
@@ -1567,7 +1533,7 @@ static int syslog_print(char __user *buf, int size)
 		} else
 			n = 0;
 		raw_spin_unlock(&syslog_lock);
-		logbuf_unlock_irq();
+		printk_safe_exit_irq();
 
 		if (!n)
 			break;
@@ -1601,7 +1567,7 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
 		return -ENOMEM;
 
 	time = printk_time;
-	logbuf_lock_irq();
+	printk_safe_enter_irq();
 	/*
 	 * Find first record that fits, including all following records,
 	 * into the user-provided buffer for this dump.
@@ -1622,12 +1588,12 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
 			break;
 		}
 
-		logbuf_unlock_irq();
+		printk_safe_exit_irq();
 		if (copy_to_user(buf + len, text, textlen))
 			len = -EFAULT;
 		else
 			len += textlen;
-		logbuf_lock_irq();
+		printk_safe_enter_irq();
 
 		if (len < 0)
 			break;
@@ -1638,7 +1604,7 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
 		latched_seq_write(&clear_seq, seq);
 		raw_spin_unlock(&syslog_lock);
 	}
-	logbuf_unlock_irq();
+	printk_safe_exit_irq();
 
 	kfree(text);
 	return len;
@@ -1646,11 +1612,11 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
 
 static void syslog_clear(void)
 {
-	logbuf_lock_irq();
+	printk_safe_enter_irq();
 	raw_spin_lock(&syslog_lock);
 	latched_seq_write(&clear_seq, prb_next_seq(prb));
 	raw_spin_unlock(&syslog_lock);
-	logbuf_unlock_irq();
+	printk_safe_exit_irq();
 }
 
 /* Return a consistent copy of @syslog_seq. */
@@ -1738,12 +1704,12 @@ int do_syslog(int type, char __user *buf, int len, int source)
 		break;
 	/* Number of chars in the log buffer */
 	case SYSLOG_ACTION_SIZE_UNREAD:
-		logbuf_lock_irq();
+		printk_safe_enter_irq();
 		raw_spin_lock(&syslog_lock);
 		if (!prb_read_valid_info(prb, syslog_seq, &info, NULL)) {
 			/* No unread messages. */
 			raw_spin_unlock(&syslog_lock);
-			logbuf_unlock_irq();
+			printk_safe_exit_irq();
 			return 0;
 		}
 		if (info.seq != syslog_seq) {
@@ -1772,7 +1738,7 @@ int do_syslog(int type, char __user *buf, int len, int source)
 			error -= syslog_partial;
 		}
 		raw_spin_unlock(&syslog_lock);
-		logbuf_unlock_irq();
+		printk_safe_exit_irq();
 		break;
 	/* Size of the log buffer */
 	case SYSLOG_ACTION_SIZE_BUFFER:
@@ -2621,7 +2587,6 @@ void console_unlock(void)
 		size_t len;
 
 		printk_safe_enter_irqsave(flags);
-		raw_spin_lock(&logbuf_lock);
 skip:
 		if (!prb_read_valid(prb, console_seq, &r))
 			break;
@@ -2665,7 +2630,6 @@ void console_unlock(void)
 				console_msg_format & MSG_FORMAT_SYSLOG,
 				printk_time);
 		console_seq++;
-		raw_spin_unlock(&logbuf_lock);
 
 		/*
 		 * While actively printing out messages, if another printk()
@@ -2692,8 +2656,6 @@ void console_unlock(void)
 
 	console_locked = 0;
 
-	raw_spin_unlock(&logbuf_lock);
-
 	up_console_sem();
 
 	/*
@@ -2702,9 +2664,7 @@ void console_unlock(void)
 	 * there's a new owner and the console_unlock() from them will do the
 	 * flush, no worries.
 	 */
-	raw_spin_lock(&logbuf_lock);
 	retry = prb_read_valid(prb, console_seq, NULL);
-	raw_spin_unlock(&logbuf_lock);
 	printk_safe_exit_irqrestore(flags);
 
 	if (retry && console_trylock())
@@ -2771,9 +2731,9 @@ void console_flush_on_panic(enum con_flush_mode mode)
 	if (mode == CONSOLE_REPLAY_ALL) {
 		unsigned long flags;
 
-		logbuf_lock_irqsave(flags);
+		printk_safe_enter_irqsave(flags);
 		console_seq = prb_first_valid_seq(prb);
-		logbuf_unlock_irqrestore(flags);
+		printk_safe_exit_irqrestore(flags);
 	}
 	console_unlock();
 }
@@ -3002,7 +2962,7 @@ void register_console(struct console *newcon)
 		 * console_unlock(); will print out the buffered messages
 		 * for us.
 		 */
-		logbuf_lock_irqsave(flags);
+		printk_safe_enter_irqsave(flags);
 		/*
 		 * We're about to replay the log buffer.  Only do this to the
 		 * just-registered console to avoid excessive message spam to
@@ -3020,7 +2980,7 @@ void register_console(struct console *newcon)
 		console_seq = syslog_seq;
 		raw_spin_unlock(&syslog_lock);
 
-		logbuf_unlock_irqrestore(flags);
+		printk_safe_exit_irqrestore(flags);
 	}
 	console_unlock();
 	console_sysfs_notify();
@@ -3406,10 +3366,10 @@ void kmsg_dump(enum kmsg_dump_reason reason)
 
 		/* initialize iterator with data about the stored records */
 		iter.active = true;
-		logbuf_lock_irqsave(flags);
+		printk_safe_enter_irqsave(flags);
 		iter.cur_seq = latched_seq_read_nolock(&clear_seq);
 		iter.next_seq = prb_next_seq(prb);
-		logbuf_unlock_irqrestore(flags);
+		printk_safe_exit_irqrestore(flags);
 
 		/* invoke dumper which will iterate over records */
 		dumper->dump(dumper, reason, &iter);
@@ -3496,9 +3456,9 @@ bool kmsg_dump_get_line(struct kmsg_dumper_iter *iter, bool syslog,
 	unsigned long flags;
 	bool ret;
 
-	logbuf_lock_irqsave(flags);
+	printk_safe_enter_irqsave(flags);
 	ret = kmsg_dump_get_line_nolock(iter, syslog, line, size, len);
-	logbuf_unlock_irqrestore(flags);
+	printk_safe_exit_irqrestore(flags);
 
 	return ret;
 }
@@ -3538,7 +3498,7 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper_iter *iter, bool syslog,
 	if (!iter->active || !buf || !size)
 		goto out;
 
-	logbuf_lock_irqsave(flags);
+	printk_safe_enter_irqsave(flags);
 	if (prb_read_valid_info(prb, iter->cur_seq, &info, NULL)) {
 		if (info.seq != iter->cur_seq) {
 			/* messages are gone, move to first available one */
@@ -3548,7 +3508,7 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper_iter *iter, bool syslog,
 
 	/* last entry */
 	if (iter->cur_seq >= iter->next_seq) {
-		logbuf_unlock_irqrestore(flags);
+		printk_safe_exit_irqrestore(flags);
 		goto out;
 	}
 
@@ -3582,7 +3542,7 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper_iter *iter, bool syslog,
 
 	iter->next_seq = next_seq;
 	ret = true;
-	logbuf_unlock_irqrestore(flags);
+	printk_safe_exit_irqrestore(flags);
 out:
 	if (len_out)
 		*len_out = len;
@@ -3618,9 +3578,9 @@ void kmsg_dump_rewind(struct kmsg_dumper_iter *iter)
 {
 	unsigned long flags;
 
-	logbuf_lock_irqsave(flags);
+	printk_safe_enter_irqsave(flags);
 	kmsg_dump_rewind_nolock(iter);
-	logbuf_unlock_irqrestore(flags);
+	printk_safe_exit_irqrestore(flags);
 }
 EXPORT_SYMBOL_GPL(kmsg_dump_rewind);
 
diff --git a/kernel/printk/printk_safe.c b/kernel/printk/printk_safe.c
index a0e6f746de6c..a9a3137bd972 100644
--- a/kernel/printk/printk_safe.c
+++ b/kernel/printk/printk_safe.c
@@ -16,7 +16,7 @@
 #include "internal.h"
 
 /*
- * printk() could not take logbuf_lock in NMI context. Instead,
+ * In NMI and safe mode, printk() avoids taking locks. Instead,
  * it uses an alternative implementation that temporary stores
  * the strings into a per-CPU buffer. The content of the buffer
  * is later flushed into the main ring buffer via IRQ work.
@@ -266,18 +266,6 @@ void printk_safe_flush(void)
  */
 void printk_safe_flush_on_panic(void)
 {
-	/*
-	 * Make sure that we could access the main ring buffer.
-	 * Do not risk a double release when more CPUs are up.
-	 */
-	if (raw_spin_is_locked(&logbuf_lock)) {
-		if (num_online_cpus() > 1)
-			return;
-
-		debug_locks_off();
-		raw_spin_lock_init(&logbuf_lock);
-	}
-
 	printk_safe_flush();
 }
 
@@ -311,9 +299,7 @@ void noinstr printk_nmi_exit(void)
  * reordering.
  *
  * It has effect only when called in NMI context. Then printk()
- * will try to store the messages into the main logbuf directly
- * and use the per-CPU buffers only as a fallback when the lock
- * is not available.
+ * will store the messages into the main logbuf directly.
  */
 void printk_nmi_direct_enter(void)
 {
@@ -368,20 +354,21 @@ __printf(1, 0) int vprintk_func(const char *fmt, va_list args)
 #endif
 
 	/*
-	 * Try to use the main logbuf even in NMI. But avoid calling console
+	 * Use the main logbuf even in NMI. But avoid calling console
 	 * drivers that might have their own locks.
 	 */
-	if ((this_cpu_read(printk_context) & PRINTK_NMI_DIRECT_CONTEXT_MASK) &&
-	    raw_spin_trylock(&logbuf_lock)) {
+	if ((this_cpu_read(printk_context) & PRINTK_NMI_DIRECT_CONTEXT_MASK)) {
+		unsigned long flags;
 		int len;
 
+		printk_safe_enter_irqsave(flags);
 		len = vprintk_store(0, LOGLEVEL_DEFAULT, NULL, fmt, args);
-		raw_spin_unlock(&logbuf_lock);
+		printk_safe_exit_irqrestore(flags);
 		defer_console_output();
 		return len;
 	}
 
-	/* Use extra buffer in NMI when logbuf_lock is taken or in safe mode. */
+	/* Use extra buffer in NMI. */
 	if (this_cpu_read(printk_context) & PRINTK_NMI_CONTEXT_MASK)
 		return vprintk_nmi(fmt, args);
 
-- 
2.20.1

Re: [PATCH printk-rework 11/14] printk: remove logbuf_lock

[Petr Mladek]

On Thu 2021-02-18 09:18:14, John Ogness wrote:
> Since the ringbuffer is lockless, there is no need for it to be
> protected by @logbuf_lock. Remove @logbuf_lock.
> 
> This means that printk_nmi_direct and printk_safe_flush_on_panic()
> no longer need to acquire any lock to run.
> 
> @console_seq, @exclusive_console_stop_seq, @console_dropped are
> protected by @console_lock.
> 
> Signed-off-by: John Ogness <john.ogness@linutronix.de>

Reviewed-by: Petr Mladek <pmladek@suse.com>

Best Regards,
Petr

[PATCH printk-rework 12/14] printk: kmsg_dump: remove _nolock() variants

[John Ogness]

kmsg_dump_rewind() and kmsg_dump_get_line() are lockless, so there is
no need for _nolock() variants. Remove these functions and switch all
callers of the _nolock() variants.

The functions without _nolock() were chosen because they are already
exported to kernel modules.

Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
 arch/powerpc/xmon/xmon.c    |  4 +--
 include/linux/kmsg_dump.h   | 18 +----------
 kernel/debug/kdb/kdb_main.c |  8 ++---
 kernel/printk/printk.c      | 60 +++++--------------------------------
 4 files changed, 15 insertions(+), 75 deletions(-)

diff --git a/arch/powerpc/xmon/xmon.c b/arch/powerpc/xmon/xmon.c
index 43162b885259..4cac114ba32d 100644
--- a/arch/powerpc/xmon/xmon.c
+++ b/arch/powerpc/xmon/xmon.c
@@ -3015,9 +3015,9 @@ dump_log_buf(void)
 	catch_memory_errors = 1;
 	sync();
 
-	kmsg_dump_rewind_nolock(&iter);
+	kmsg_dump_rewind(&iter);
 	xmon_start_pagination();
-	while (kmsg_dump_get_line_nolock(&iter, false, buf, sizeof(buf), &len)) {
+	while (kmsg_dump_get_line(&iter, false, buf, sizeof(buf), &len)) {
 		buf[len] = '\0';
 		printf("%s", buf);
 	}
diff --git a/include/linux/kmsg_dump.h b/include/linux/kmsg_dump.h
index 2fdb10ab1799..86673930c8ea 100644
--- a/include/linux/kmsg_dump.h
+++ b/include/linux/kmsg_dump.h
@@ -60,18 +60,13 @@ struct kmsg_dumper {
 #ifdef CONFIG_PRINTK
 void kmsg_dump(enum kmsg_dump_reason reason);
 
-bool kmsg_dump_get_line_nolock(struct kmsg_dumper_iter *iter, bool syslog,
-			       char *line, size_t size, size_t *len);
-
 bool kmsg_dump_get_line(struct kmsg_dumper_iter *iter, bool syslog,
 			char *line, size_t size, size_t *len);
 
 bool kmsg_dump_get_buffer(struct kmsg_dumper_iter *iter, bool syslog,
 			  char *buf, size_t size, size_t *len_out);
 
-void kmsg_dump_rewind_nolock(struct kmsg_dumper_iter *iter);
-
-void kmsg_dump_rewind(struct kmsg_dumper_iter *dumper_iter);
+void kmsg_dump_rewind(struct kmsg_dumper_iter *iter);
 
 int kmsg_dump_register(struct kmsg_dumper *dumper);
 
@@ -83,13 +78,6 @@ static inline void kmsg_dump(enum kmsg_dump_reason reason)
 {
 }
 
-static inline bool kmsg_dump_get_line_nolock(struct kmsg_dumper_iter *iter,
-					     bool syslog, const char *line,
-					     size_t size, size_t *len)
-{
-	return false;
-}
-
 static inline bool kmsg_dump_get_line(struct kmsg_dumper_iter *iter, bool syslog,
 				const char *line, size_t size, size_t *len)
 {
@@ -102,10 +90,6 @@ static inline bool kmsg_dump_get_buffer(struct kmsg_dumper_iter *iter, bool sysl
 	return false;
 }
 
-static inline void kmsg_dump_rewind_nolock(struct kmsg_dumper_iter *iter)
-{
-}
-
 static inline void kmsg_dump_rewind(struct kmsg_dumper_iter *iter)
 {
 }
diff --git a/kernel/debug/kdb/kdb_main.c b/kernel/debug/kdb/kdb_main.c
index 7ae9da245e4b..dbf1d126ac5e 100644
--- a/kernel/debug/kdb/kdb_main.c
+++ b/kernel/debug/kdb/kdb_main.c
@@ -2126,8 +2126,8 @@ static int kdb_dmesg(int argc, const char **argv)
 		kdb_set(2, setargs);
 	}
 
-	kmsg_dump_rewind_nolock(&iter);
-	while (kmsg_dump_get_line_nolock(&iter, 1, NULL, 0, NULL))
+	kmsg_dump_rewind(&iter);
+	while (kmsg_dump_get_line(&iter, 1, NULL, 0, NULL))
 		n++;
 
 	if (lines < 0) {
@@ -2159,8 +2159,8 @@ static int kdb_dmesg(int argc, const char **argv)
 	if (skip >= n || skip < 0)
 		return 0;
 
-	kmsg_dump_rewind_nolock(&iter);
-	while (kmsg_dump_get_line_nolock(&iter, 1, buf, sizeof(buf), &len)) {
+	kmsg_dump_rewind(&iter);
+	while (kmsg_dump_get_line(&iter, 1, buf, sizeof(buf), &len)) {
 		if (skip) {
 			skip--;
 			continue;
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index c5ea46ed88c7..744b806d5457 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -3378,7 +3378,7 @@ void kmsg_dump(enum kmsg_dump_reason reason)
 }
 
 /**
- * kmsg_dump_get_line_nolock - retrieve one kmsg log line (unlocked version)
+ * kmsg_dump_get_line - retrieve one kmsg log line
  * @iter: kmsg dumper iterator
  * @syslog: include the "<4>" prefixes
  * @line: buffer to copy the line to
@@ -3393,18 +3393,18 @@ void kmsg_dump(enum kmsg_dump_reason reason)
  *
  * A return value of FALSE indicates that there are no more records to
  * read.
- *
- * The function is similar to kmsg_dump_get_line(), but grabs no locks.
  */
-bool kmsg_dump_get_line_nolock(struct kmsg_dumper_iter *iter, bool syslog,
-			       char *line, size_t size, size_t *len)
+bool kmsg_dump_get_line(struct kmsg_dumper_iter *iter, bool syslog,
+			char *line, size_t size, size_t *len)
 {
 	struct printk_info info;
 	unsigned int line_count;
 	struct printk_record r;
+	unsigned long flags;
 	size_t l = 0;
 	bool ret = false;
 
+	printk_safe_enter_irqsave(flags);
 	prb_rec_init_rd(&r, &info, line, size);
 
 	if (!iter->active)
@@ -3428,40 +3428,11 @@ bool kmsg_dump_get_line_nolock(struct kmsg_dumper_iter *iter, bool syslog,
 	iter->cur_seq = r.info->seq + 1;
 	ret = true;
 out:
+	printk_safe_exit_irqrestore(flags);
 	if (len)
 		*len = l;
 	return ret;
 }
-
-/**
- * kmsg_dump_get_line - retrieve one kmsg log line
- * @iter: kmsg dumper iterator
- * @syslog: include the "<4>" prefixes
- * @line: buffer to copy the line to
- * @size: maximum size of the buffer
- * @len: length of line placed into buffer
- *
- * Start at the beginning of the kmsg buffer, with the oldest kmsg
- * record, and copy one record into the provided buffer.
- *
- * Consecutive calls will return the next available record moving
- * towards the end of the buffer with the youngest messages.
- *
- * A return value of FALSE indicates that there are no more records to
- * read.
- */
-bool kmsg_dump_get_line(struct kmsg_dumper_iter *iter, bool syslog,
-			char *line, size_t size, size_t *len)
-{
-	unsigned long flags;
-	bool ret;
-
-	printk_safe_enter_irqsave(flags);
-	ret = kmsg_dump_get_line_nolock(iter, syslog, line, size, len);
-	printk_safe_exit_irqrestore(flags);
-
-	return ret;
-}
 EXPORT_SYMBOL_GPL(kmsg_dump_get_line);
 
 /**
@@ -3550,22 +3521,6 @@ bool kmsg_dump_get_buffer(struct kmsg_dumper_iter *iter, bool syslog,
 }
 EXPORT_SYMBOL_GPL(kmsg_dump_get_buffer);
 
-/**
- * kmsg_dump_rewind_nolock - reset the iterator (unlocked version)
- * @iter: kmsg dumper iterator
- *
- * Reset the dumper's iterator so that kmsg_dump_get_line() and
- * kmsg_dump_get_buffer() can be called again and used multiple
- * times within the same dumper.dump() callback.
- *
- * The function is similar to kmsg_dump_rewind(), but grabs no locks.
- */
-void kmsg_dump_rewind_nolock(struct kmsg_dumper_iter *iter)
-{
-	iter->cur_seq = latched_seq_read_nolock(&clear_seq);
-	iter->next_seq = prb_next_seq(prb);
-}
-
 /**
  * kmsg_dump_rewind - reset the iterator
  * @iter: kmsg dumper iterator
@@ -3579,7 +3534,8 @@ void kmsg_dump_rewind(struct kmsg_dumper_iter *iter)
 	unsigned long flags;
 
 	printk_safe_enter_irqsave(flags);
-	kmsg_dump_rewind_nolock(iter);
+	iter->cur_seq = latched_seq_read_nolock(&clear_seq);
+	iter->next_seq = prb_next_seq(prb);
 	printk_safe_exit_irqrestore(flags);
 }
 EXPORT_SYMBOL_GPL(kmsg_dump_rewind);
-- 
2.20.1

Re: [PATCH printk-rework 12/14] printk: kmsg_dump: remove _nolock() variants

[Petr Mladek]

On Thu 2021-02-18 09:18:15, John Ogness wrote:
> kmsg_dump_rewind() and kmsg_dump_get_line() are lockless, so there is
> no need for _nolock() variants. Remove these functions and switch all
> callers of the _nolock() variants.
> 
> The functions without _nolock() were chosen because they are already
> exported to kernel modules.
> 
> Signed-off-by: John Ogness <john.ogness@linutronix.de>

Reviewed-by: Petr Mladek <pmladek@suse.com>

Best Regards,
Petr

[PATCH printk-rework 13/14] printk: kmsg_dump: use kmsg_dump_rewind

[John Ogness]

kmsg_dump() is open coding the kmsg_dump_rewind(). Call
kmsg_dump_rewind() instead.

Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
 kernel/printk/printk.c | 6 +-----
 1 file changed, 1 insertion(+), 5 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 744b806d5457..23d525e885e7 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -3347,7 +3347,6 @@ void kmsg_dump(enum kmsg_dump_reason reason)
 {
 	struct kmsg_dumper_iter iter;
 	struct kmsg_dumper *dumper;
-	unsigned long flags;
 
 	rcu_read_lock();
 	list_for_each_entry_rcu(dumper, &dump_list, list) {
@@ -3366,10 +3365,7 @@ void kmsg_dump(enum kmsg_dump_reason reason)
 
 		/* initialize iterator with data about the stored records */
 		iter.active = true;
-		printk_safe_enter_irqsave(flags);
-		iter.cur_seq = latched_seq_read_nolock(&clear_seq);
-		iter.next_seq = prb_next_seq(prb);
-		printk_safe_exit_irqrestore(flags);
+		kmsg_dump_rewind(&iter);
 
 		/* invoke dumper which will iterate over records */
 		dumper->dump(dumper, reason, &iter);
-- 
2.20.1

Re: [PATCH printk-rework 13/14] printk: kmsg_dump: use kmsg_dump_rewind

[Petr Mladek]

On Thu 2021-02-18 09:18:16, John Ogness wrote:
> kmsg_dump() is open coding the kmsg_dump_rewind(). Call
> kmsg_dump_rewind() instead.
> 
> Signed-off-by: John Ogness <john.ogness@linutronix.de>

Reviewed-by: Petr Mladek <pmladek@suse.com>

Best Regards,
Petr

[PATCH printk-rework 14/14] printk: console: remove unnecessary safe buffer usage

[John Ogness]

Upon registering a console, safe buffers are activated when setting
up the sequence number to replay the log. However, these are already
protected by @console_sem and @syslog_lock. Remove the unnecessary
safe buffer usage.

Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
 kernel/printk/printk.c | 10 +++-------
 1 file changed, 3 insertions(+), 7 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 23d525e885e7..78eee6c553a5 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2961,9 +2961,7 @@ void register_console(struct console *newcon)
 		/*
 		 * console_unlock(); will print out the buffered messages
 		 * for us.
-		 */
-		printk_safe_enter_irqsave(flags);
-		/*
+		 *
 		 * We're about to replay the log buffer.  Only do this to the
 		 * just-registered console to avoid excessive message spam to
 		 * the already-registered consoles.
@@ -2976,11 +2974,9 @@ void register_console(struct console *newcon)
 		exclusive_console_stop_seq = console_seq;
 
 		/* Get a consistent copy of @syslog_seq. */
-		raw_spin_lock(&syslog_lock);
+		raw_spin_lock_irqsave(&syslog_lock, flags);
 		console_seq = syslog_seq;
-		raw_spin_unlock(&syslog_lock);
-
-		printk_safe_exit_irqrestore(flags);
+		raw_spin_unlock_irqrestore(&syslog_lock, flags);
 	}
 	console_unlock();
 	console_sysfs_notify();
-- 
2.20.1

Re: [PATCH printk-rework 14/14] printk: console: remove unnecessary safe buffer usage

[Petr Mladek]

On Thu 2021-02-18 09:18:17, John Ogness wrote:
> Upon registering a console, safe buffers are activated when setting
> up the sequence number to replay the log. However, these are already
> protected by @console_sem and @syslog_lock. Remove the unnecessary
> safe buffer usage.
> 
> Signed-off-by: John Ogness <john.ogness@linutronix.de>

Reviewed-by: Petr Mladek <pmladek@suse.com>

Best Regards,
Petr