All of lore.kernel.org
 help / color / mirror / Atom feed
* [PATCH printk v4 0/8] printk: cleanup buffer handling
@ 2023-01-05 10:37 John Ogness
  2023-01-05 10:37 ` [PATCH printk v4 1/8] printk: move size limit macros into internal.h John Ogness
                   ` (8 more replies)
  0 siblings, 9 replies; 22+ messages in thread
From: John Ogness @ 2023-01-05 10:37 UTC (permalink / raw)
  To: Petr Mladek
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner,
	linux-kernel, Greg Kroah-Hartman

Hi,

This is v4 of a series to cleanup console buffer handling and
prepare for code sharing with the upcoming threaded/atomic
consoles. v3 is here [0].

The main purpose of the series is to introduce two new lockless
functions to handle reading and formatting of printk messages. These
functions can then be used from any context, which is important for
the upcoming threaded/atomic consoles. The series also helps to
cleanup some of the internal printk interfaces and cleanly separate
formatting code from outputting code.

Some changes in this version were not part of the feedback. However,
from the discussions and examples I decided that some of the names
I had previously chosen were not appropriate. Particularly, structs,
variables, and functions should only use the "console_" prefix if it
is console-specific. Things that are used for general printk
processing should use a "printk_" prefix. This makes the diff to v3
rather large, even though the "real code" has only minor changes.

@Petr: Like with v3, this version uses a wrapper struct for the
message metadata to avoid clobbering. Making the message formatting
code robust enough to handle metadata clobbering was too complex
(particularly with the dropped tracking).

Changes since v3:

- Provide a detailed explanation in the commit message about why
  message metadata is put into a wrapper struct instead of the
  buffer struct.

- Reorder stack variable definitions so that static variables are at
  the top and separated from non-static variables. IMHO it is
  important to clearly see which of the variables are static.

- Drop a previous coding-style change from a line not related to
  this series.

- In console_prepend_dropped() make sure the buffer is large enough
  for the dropped message and at least PREFIX_MAX of the current
  message.

- Define the PREFIX_MAX macro for !CONFIG_PRINTK in internal.h
  because console_prepend_dropped() now needs it.

- Rename various functions, structs, fields, and macros:

    console_get_next_message()  ->  printk_get_next_message()

    struct console_buffers      ->  struct printk_buffers

    struct console_message      ->  struct printk_message

    console_message.cbufs       ->  printk_message.pbufs

    console_message.outbuf_seq  ->  printk_message.seq

    LOG_LINE_MAX                ->  PRINTKRB_RECORD_MAX

    PREFIX_MAX                  ->  PRINTK_PREFIX_MAX

    CONSOLE_LOG_MAX and
    CONSOLE_EXT_LOG_MAX         ->  PRINTK_MESSAGE_MAX

- Adjust the values of string limit macros. This is explained in
  detail in the commit message.

- Replace @buf and @text_buf in struct devkmsg_user with struct
  printk_buffers.

- Replace message formatting code in devkmsg_read() with
  printk_get_next_message().

- Define all printk_message structs on the stack.

John Ogness

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

John Ogness (6):
  printk: move size limit macros into internal.h
  printk: introduce struct printk_buffers
  printk: introduce printk_get_next_message() and printk_message
  printk: introduce console_prepend_dropped() for dropped messages
  printk: use printk_buffers for devkmsg
  printk: adjust string limit macros

Thomas Gleixner (2):
  console: Use BIT() macros for @flags values
  console: Document struct console

 include/linux/console.h  | 100 +++++++++----
 include/linux/printk.h   |   2 -
 kernel/printk/internal.h |  45 ++++++
 kernel/printk/printk.c   | 293 +++++++++++++++++++++++----------------
 4 files changed, 288 insertions(+), 152 deletions(-)


base-commit: 6b2b0d839acaa84f05a77184370f793752e786e9
-- 
2.30.2


^ permalink raw reply	[flat|nested] 22+ messages in thread

* [PATCH printk v4 1/8] printk: move size limit macros into internal.h
  2023-01-05 10:37 [PATCH printk v4 0/8] printk: cleanup buffer handling John Ogness
@ 2023-01-05 10:37 ` John Ogness
  2023-01-05 14:48   ` Petr Mladek
  2023-01-05 10:37 ` [PATCH printk v4 2/8] console: Use BIT() macros for @flags values John Ogness
                   ` (7 subsequent siblings)
  8 siblings, 1 reply; 22+ messages in thread
From: John Ogness @ 2023-01-05 10:37 UTC (permalink / raw)
  To: Petr Mladek
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner, linux-kernel

The size limit macros are located further down in printk.c and
behind ifdef conditionals. This complicates their usage for
upcoming changes. Move the macros into internal.h so that they
are still invisible outside of printk, but easily accessible
for printk.

Also, the maximum size of formatted extended messages does not
need to be known by any code outside of printk, so move it to
internal.h as well. And like CONSOLE_LOG_MAX, for !CONFIG_PRINTK
set CONSOLE_EXT_LOG_MAX to 0 to reduce the static memory
footprint.

Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
 include/linux/printk.h   |  2 --
 kernel/printk/internal.h | 24 ++++++++++++++++++++++++
 kernel/printk/printk.c   | 17 -----------------
 3 files changed, 24 insertions(+), 19 deletions(-)

diff --git a/include/linux/printk.h b/include/linux/printk.h
index 8c81806c2e99..8ef499ab3c1e 100644
--- a/include/linux/printk.h
+++ b/include/linux/printk.h
@@ -44,8 +44,6 @@ static inline const char *printk_skip_headers(const char *buffer)
 	return buffer;
 }
 
-#define CONSOLE_EXT_LOG_MAX	8192
-
 /* printk's without a loglevel use this.. */
 #define MESSAGE_LOGLEVEL_DEFAULT CONFIG_MESSAGE_LOGLEVEL_DEFAULT
 
diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
index d947ca6c84f9..f394332410c9 100644
--- a/kernel/printk/internal.h
+++ b/kernel/printk/internal.h
@@ -14,6 +14,24 @@ int devkmsg_sysctl_set_loglvl(struct ctl_table *table, int write,
 
 #ifdef CONFIG_PRINTK
 
+#ifdef CONFIG_PRINTK_CALLER
+#define PREFIX_MAX		48
+#else
+#define PREFIX_MAX		32
+#endif
+
+/* the maximum size of a formatted record (i.e. with prefix added per line) */
+#define CONSOLE_LOG_MAX		1024
+
+/* the maximum size of a formatted extended record */
+#define CONSOLE_EXT_LOG_MAX	8192
+
+/* the maximum size for a dropped text message */
+#define DROPPED_TEXT_MAX	64
+
+/* the maximum size allowed to be reserved for a record */
+#define LOG_LINE_MAX		(CONSOLE_LOG_MAX - PREFIX_MAX)
+
 /* Flags for a single printk record. */
 enum printk_info_flags {
 	LOG_NEWLINE	= 2,	/* text ended with a newline */
@@ -48,6 +66,12 @@ u16 printk_parse_prefix(const char *text, int *level,
 			enum printk_info_flags *flags);
 #else
 
+#define PREFIX_MAX		0
+#define CONSOLE_LOG_MAX		0
+#define CONSOLE_EXT_LOG_MAX	0
+#define DROPPED_TEXT_MAX	0
+#define LOG_LINE_MAX		0
+
 /*
  * In !PRINTK builds we still export console_sem
  * semaphore and some of console functions (console_unlock()/etc.), so
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 7decf1e9c486..55bb065de65f 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -465,21 +465,6 @@ static struct latched_seq clear_seq = {
 	.val[1]		= 0,
 };
 
-#ifdef CONFIG_PRINTK_CALLER
-#define PREFIX_MAX		48
-#else
-#define PREFIX_MAX		32
-#endif
-
-/* the maximum size of a formatted record (i.e. with prefix added per line) */
-#define CONSOLE_LOG_MAX		1024
-
-/* the maximum size for a dropped text message */
-#define DROPPED_TEXT_MAX	64
-
-/* the maximum size allowed to be reserved for a record */
-#define LOG_LINE_MAX		(CONSOLE_LOG_MAX - PREFIX_MAX)
-
 #define LOG_LEVEL(v)		((v) & 0x07)
 #define LOG_FACILITY(v)		((v) >> 3 & 0xff)
 
@@ -2387,8 +2372,6 @@ static bool __pr_flush(struct console *con, int timeout_ms, bool reset_on_progre
 
 #else /* CONFIG_PRINTK */
 
-#define CONSOLE_LOG_MAX		0
-#define DROPPED_TEXT_MAX	0
 #define printk_time		false
 
 #define prb_read_valid(rb, seq, r)	false
-- 
2.30.2


^ permalink raw reply related	[flat|nested] 22+ messages in thread

* [PATCH printk v4 2/8] console: Use BIT() macros for @flags values
  2023-01-05 10:37 [PATCH printk v4 0/8] printk: cleanup buffer handling John Ogness
  2023-01-05 10:37 ` [PATCH printk v4 1/8] printk: move size limit macros into internal.h John Ogness
@ 2023-01-05 10:37 ` John Ogness
  2023-01-05 10:37 ` [PATCH printk v4 3/8] console: Document struct console John Ogness
                   ` (6 subsequent siblings)
  8 siblings, 0 replies; 22+ messages in thread
From: John Ogness @ 2023-01-05 10:37 UTC (permalink / raw)
  To: Petr Mladek
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner,
	linux-kernel, Greg Kroah-Hartman

From: Thomas Gleixner <tglx@linutronix.de>

Rather than manually calculating powers of 2, use the BIT() macros.
Also take this opportunatity to cleanup and restructure the value
comments into proper kerneldoc comments.

Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Signed-off-by: John Ogness <john.ogness@linutronix.de>
Reviewed-by: Petr Mladek <pmladek@suse.com>
---
 include/linux/console.h | 46 ++++++++++++++++++++++++++++++++---------
 1 file changed, 36 insertions(+), 10 deletions(-)

diff --git a/include/linux/console.h b/include/linux/console.h
index 9cea254b34b8..ed804dd7c2e8 100644
--- a/include/linux/console.h
+++ b/include/linux/console.h
@@ -15,6 +15,7 @@
 #define _LINUX_CONSOLE_H_ 1
 
 #include <linux/atomic.h>
+#include <linux/bits.h>
 #include <linux/rculist.h>
 #include <linux/types.h>
 
@@ -125,18 +126,43 @@ static inline int con_debug_leave(void)
 /*
  * The interface for a console, or any other device that wants to capture
  * console messages (printer driver?)
- *
- * If a console driver is marked CON_BOOT then it will be auto-unregistered
- * when the first real console is registered.  This is for early-printk drivers.
  */
 
-#define CON_PRINTBUFFER	(1)
-#define CON_CONSDEV	(2) /* Preferred console, /dev/console */
-#define CON_ENABLED	(4)
-#define CON_BOOT	(8)
-#define CON_ANYTIME	(16) /* Safe to call when cpu is offline */
-#define CON_BRL		(32) /* Used for a braille device */
-#define CON_EXTENDED	(64) /* Use the extended output format a la /dev/kmsg */
+/**
+ * cons_flags - General console flags
+ * @CON_PRINTBUFFER:	Used by newly registered consoles to avoid duplicate
+ *			output of messages that were already shown by boot
+ *			consoles or read by userspace via syslog() syscall.
+ * @CON_CONSDEV:	Indicates that the console driver is backing
+ *			/dev/console.
+ * @CON_ENABLED:	Indicates if a console is allowed to print records. If
+ *			false, the console also will not advance to later
+ *			records.
+ * @CON_BOOT:		Marks the console driver as early console driver which
+ *			is used during boot before the real driver becomes
+ *			available. It will be automatically unregistered
+ *			when the real console driver is registered unless
+ *			"keep_bootcon" parameter is used.
+ * @CON_ANYTIME:	A misnomed historical flag which tells the core code
+ *			that the legacy @console::write callback can be invoked
+ *			on a CPU which is marked OFFLINE. That is misleading as
+ *			it suggests that there is no contextual limit for
+ *			invoking the callback. The original motivation was
+ *			readiness of the per-CPU areas.
+ * @CON_BRL:		Indicates a braille device which is exempt from
+ *			receiving the printk spam for obvious reasons.
+ * @CON_EXTENDED:	The console supports the extended output format of
+ *			/dev/kmesg which requires a larger output buffer.
+ */
+enum cons_flags {
+	CON_PRINTBUFFER		= BIT(0),
+	CON_CONSDEV		= BIT(1),
+	CON_ENABLED		= BIT(2),
+	CON_BOOT		= BIT(3),
+	CON_ANYTIME		= BIT(4),
+	CON_BRL			= BIT(5),
+	CON_EXTENDED		= BIT(6),
+};
 
 struct console {
 	char	name[16];
-- 
2.30.2


^ permalink raw reply related	[flat|nested] 22+ messages in thread

* [PATCH printk v4 3/8] console: Document struct console
  2023-01-05 10:37 [PATCH printk v4 0/8] printk: cleanup buffer handling John Ogness
  2023-01-05 10:37 ` [PATCH printk v4 1/8] printk: move size limit macros into internal.h John Ogness
  2023-01-05 10:37 ` [PATCH printk v4 2/8] console: Use BIT() macros for @flags values John Ogness
@ 2023-01-05 10:37 ` John Ogness
  2023-01-05 10:37 ` [PATCH printk v4 4/8] printk: introduce struct printk_buffers John Ogness
                   ` (5 subsequent siblings)
  8 siblings, 0 replies; 22+ messages in thread
From: John Ogness @ 2023-01-05 10:37 UTC (permalink / raw)
  To: Petr Mladek
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner,
	linux-kernel, Greg Kroah-Hartman

From: Thomas Gleixner <tglx@linutronix.de>

Add kerneldoc comments to struct console.

Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Signed-off-by: John Ogness <john.ogness@linutronix.de>
Reviewed-by: Petr Mladek <pmladek@suse.com>
---
 include/linux/console.h | 54 ++++++++++++++++++++++++++++-------------
 1 file changed, 37 insertions(+), 17 deletions(-)

diff --git a/include/linux/console.h b/include/linux/console.h
index ed804dd7c2e8..1e36958aa656 100644
--- a/include/linux/console.h
+++ b/include/linux/console.h
@@ -164,24 +164,44 @@ enum cons_flags {
 	CON_EXTENDED		= BIT(6),
 };
 
+/**
+ * struct console - The console descriptor structure
+ * @name:		The name of the console driver
+ * @write:		Write callback to output messages (Optional)
+ * @read:		Read callback for console input (Optional)
+ * @device:		The underlying TTY device driver (Optional)
+ * @unblank:		Callback to unblank the console (Optional)
+ * @setup:		Callback for initializing the console (Optional)
+ * @exit:		Callback for teardown of the console (Optional)
+ * @match:		Callback for matching a console (Optional)
+ * @flags:		Console flags. See enum cons_flags
+ * @index:		Console index, e.g. port number
+ * @cflag:		TTY control mode flags
+ * @ispeed:		TTY input speed
+ * @ospeed:		TTY output speed
+ * @seq:		Sequence number of the next ringbuffer record to print
+ * @dropped:		Number of unreported dropped ringbuffer records
+ * @data:		Driver private data
+ * @node:		hlist node for the console list
+ */
 struct console {
-	char	name[16];
-	void	(*write)(struct console *, const char *, unsigned);
-	int	(*read)(struct console *, char *, unsigned);
-	struct tty_driver *(*device)(struct console *, int *);
-	void	(*unblank)(void);
-	int	(*setup)(struct console *, char *);
-	int	(*exit)(struct console *);
-	int	(*match)(struct console *, char *name, int idx, char *options);
-	short	flags;
-	short	index;
-	int	cflag;
-	uint	ispeed;
-	uint	ospeed;
-	u64	seq;
-	unsigned long dropped;
-	void	*data;
-	struct hlist_node node;
+	char			name[16];
+	void			(*write)(struct console *co, const char *s, unsigned int count);
+	int			(*read)(struct console *co, char *s, unsigned int count);
+	struct tty_driver	*(*device)(struct console *co, int *index);
+	void			(*unblank)(void);
+	int			(*setup)(struct console *co, char *options);
+	int			(*exit)(struct console *co);
+	int			(*match)(struct console *co, char *name, int idx, char *options);
+	short			flags;
+	short			index;
+	int			cflag;
+	uint			ispeed;
+	uint			ospeed;
+	u64			seq;
+	unsigned long		dropped;
+	void			*data;
+	struct hlist_node	node;
 };
 
 #ifdef CONFIG_LOCKDEP
-- 
2.30.2


^ permalink raw reply related	[flat|nested] 22+ messages in thread

* [PATCH printk v4 4/8] printk: introduce struct printk_buffers
  2023-01-05 10:37 [PATCH printk v4 0/8] printk: cleanup buffer handling John Ogness
                   ` (2 preceding siblings ...)
  2023-01-05 10:37 ` [PATCH printk v4 3/8] console: Document struct console John Ogness
@ 2023-01-05 10:37 ` John Ogness
  2023-01-05 15:06   ` Petr Mladek
  2023-01-05 10:37 ` [PATCH printk v4 5/8] printk: introduce printk_get_next_message() and printk_message John Ogness
                   ` (4 subsequent siblings)
  8 siblings, 1 reply; 22+ messages in thread
From: John Ogness @ 2023-01-05 10:37 UTC (permalink / raw)
  To: Petr Mladek
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner, linux-kernel

Introduce a new struct printk_buffers to contain all the buffers
needed to read and format a printk message for output. Putting the
buffers inside a struct reduces the number of buffer pointers that
need to be tracked. Also, it allows usage of the sizeof() macro for
the buffer sizes, rather than expecting certain sized buffers being
passed in.

Note that since the output buffer for normal consoles is now
CONSOLE_EXT_LOG_MAX instead of CONSOLE_LOG_MAX, multi-line
messages that may have been previously truncated will now be
printed in full. This should be considered a feature and not a bug
since the CONSOLE_LOG_MAX restriction was about limiting static
buffer usage rather than limiting printed text.

Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
 kernel/printk/internal.h | 10 +++++++
 kernel/printk/printk.c   | 57 ++++++++++++++++++----------------------
 2 files changed, 36 insertions(+), 31 deletions(-)

diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
index f394332410c9..6080d289a342 100644
--- a/kernel/printk/internal.h
+++ b/kernel/printk/internal.h
@@ -82,3 +82,13 @@ u16 printk_parse_prefix(const char *text, int *level,
 
 static inline bool printk_percpu_data_ready(void) { return false; }
 #endif /* CONFIG_PRINTK */
+
+/**
+ * struct printk_buffers - Buffers to read/format/output printk messages.
+ * @outbuf:	After formatting, contains text to output.
+ * @scratchbuf:	Used as temporary ringbuffer reading and string-print space.
+ */
+struct printk_buffers {
+	char	outbuf[CONSOLE_EXT_LOG_MAX];
+	char	scratchbuf[LOG_LINE_MAX];
+};
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 55bb065de65f..bc5d4574c459 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2728,14 +2728,6 @@ static void __console_unlock(void)
  * Print one record for the given console. The record printed is whatever
  * record is the next available record for the given console.
  *
- * @text is a buffer of size CONSOLE_LOG_MAX.
- *
- * If extended messages should be printed, @ext_text is a buffer of size
- * CONSOLE_EXT_LOG_MAX. Otherwise @ext_text must be NULL.
- *
- * If dropped messages should be printed, @dropped_text is a buffer of size
- * DROPPED_TEXT_MAX. Otherwise @dropped_text must be NULL.
- *
  * @handover will be set to true if a printk waiter has taken over the
  * console_lock, in which case the caller is no longer holding both the
  * console_lock and the SRCU read lock. Otherwise it is set to false.
@@ -2747,17 +2739,33 @@ static void __console_unlock(void)
  *
  * Requires the console_lock and the SRCU read lock.
  */
-static bool console_emit_next_record(struct console *con, char *text, char *ext_text,
-				     char *dropped_text, bool *handover, int cookie)
+static bool console_emit_next_record(struct console *con, bool *handover, int cookie)
 {
+	static char dropped_text[DROPPED_TEXT_MAX];
+	static struct printk_buffers pbufs;
 	static int panic_console_dropped;
+
+	bool is_extended = console_srcu_read_flags(con) & CON_EXTENDED;
+	const size_t scratchbuf_sz = sizeof(pbufs.scratchbuf);
+	const size_t outbuf_sz = sizeof(pbufs.outbuf);
+	char *scratchbuf = &pbufs.scratchbuf[0];
+	char *outbuf = &pbufs.outbuf[0];
 	struct printk_info info;
 	struct printk_record r;
 	unsigned long flags;
-	char *write_text;
 	size_t len;
 
-	prb_rec_init_rd(&r, &info, text, CONSOLE_LOG_MAX);
+	/*
+	 * Formatting extended messages requires a separate buffer, so use the
+	 * scratch buffer to read in the ringbuffer text.
+	 *
+	 * Formatting normal messages is done in-place, so read the ringbuffer
+	 * text directly into the output buffer.
+	 */
+	if (is_extended)
+		prb_rec_init_rd(&r, &info, scratchbuf, scratchbuf_sz);
+	else
+		prb_rec_init_rd(&r, &info, outbuf, outbuf_sz);
 
 	*handover = false;
 
@@ -2779,13 +2787,11 @@ static bool console_emit_next_record(struct console *con, char *text, char *ext_
 		goto skip;
 	}
 
-	if (ext_text) {
-		write_text = ext_text;
-		len = info_print_ext_header(ext_text, CONSOLE_EXT_LOG_MAX, r.info);
-		len += msg_print_ext_body(ext_text + len, CONSOLE_EXT_LOG_MAX - len,
+	if (is_extended) {
+		len = info_print_ext_header(outbuf, outbuf_sz, r.info);
+		len += msg_print_ext_body(outbuf + len, outbuf_sz - len,
 					  &r.text_buf[0], r.info->text_len, &r.info->dev_info);
 	} else {
-		write_text = text;
 		len = record_print_text(&r, console_msg_format & MSG_FORMAT_SYSLOG, printk_time);
 	}
 
@@ -2803,7 +2809,8 @@ static bool console_emit_next_record(struct console *con, char *text, char *ext_
 	console_lock_spinning_enable();
 
 	stop_critical_timings();	/* don't trace print latency */
-	call_console_driver(con, write_text, len, dropped_text);
+	call_console_driver(con, outbuf, len,
+			    is_extended ? NULL : dropped_text);
 	start_critical_timings();
 
 	con->seq++;
@@ -2839,9 +2846,6 @@ static bool console_emit_next_record(struct console *con, char *text, char *ext_
  */
 static bool console_flush_all(bool do_cond_resched, u64 *next_seq, bool *handover)
 {
-	static char dropped_text[DROPPED_TEXT_MAX];
-	static char ext_text[CONSOLE_EXT_LOG_MAX];
-	static char text[CONSOLE_LOG_MAX];
 	bool any_usable = false;
 	struct console *con;
 	bool any_progress;
@@ -2861,16 +2865,7 @@ static bool console_flush_all(bool do_cond_resched, u64 *next_seq, bool *handove
 				continue;
 			any_usable = true;
 
-			if (console_srcu_read_flags(con) & CON_EXTENDED) {
-				/* Extended consoles do not print "dropped messages". */
-				progress = console_emit_next_record(con, &text[0],
-								    &ext_text[0], NULL,
-								    handover, cookie);
-			} else {
-				progress = console_emit_next_record(con, &text[0],
-								    NULL, &dropped_text[0],
-								    handover, cookie);
-			}
+			progress = console_emit_next_record(con, handover, cookie);
 
 			/*
 			 * If a handover has occurred, the SRCU read lock
-- 
2.30.2


^ permalink raw reply related	[flat|nested] 22+ messages in thread

* [PATCH printk v4 5/8] printk: introduce printk_get_next_message() and printk_message
  2023-01-05 10:37 [PATCH printk v4 0/8] printk: cleanup buffer handling John Ogness
                   ` (3 preceding siblings ...)
  2023-01-05 10:37 ` [PATCH printk v4 4/8] printk: introduce struct printk_buffers John Ogness
@ 2023-01-05 10:37 ` John Ogness
  2023-01-05 15:24   ` Petr Mladek
  2023-01-05 10:37 ` [PATCH printk v4 6/8] printk: introduce console_prepend_dropped() for dropped messages John Ogness
                   ` (3 subsequent siblings)
  8 siblings, 1 reply; 22+ messages in thread
From: John Ogness @ 2023-01-05 10:37 UTC (permalink / raw)
  To: Petr Mladek
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner, linux-kernel

Code for performing the console output is intermixed with code that
is formatting the output for that console. Introduce a new helper
function printk_get_next_message() to handle the reading and
formatting of the printk text. The helper does not require any
locking so that in the future it can be used for other printing
contexts as well.

This also introduces a new struct printk_message to wrap the struct
printk_buffers, adding metadata about its contents. This allows
users of printk_get_next_message() to receive all relevant
information about the message that was read and formatted.

Why is struct printk_message a wrapper struct?

It is intentional that a wrapper struct is introduced instead of
adding the metadata directly to struct printk_buffers. The upcoming
atomic consoles support multiple printing contexts per CPU. This
means that while a CPU is formatting a message, it can be
interrupted and the interrupting context may also format a (possibly
different) message. Since the printk buffers are rather large,
there will only be one struct printk_buffers per CPU and it must be
shared by the possible contexts of that CPU.

If the metadata was part of struct printk_buffers, interrupting
contexts would clobber the metadata being prepared by the
interrupted context. This could be handled by robustifying the
message formatting functions to cope with metadata unexpectedly
changing. However, this would require significant amounts of extra
data copying, also adding significant complexity to the code.

Instead, the metadata can live on the stack of the formatting
context and the message formatting functions do not need to be
concerned about the metadata changing underneath them.

Note that the message formatting functions can handle unexpected
text buffer changes. So it is perfectly OK if a shared text buffer
is clobbered by an interrupting context. The atomic console
implementation will recognize the interruption and avoid printing
the (probably garbage) text buffer.

Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
 kernel/printk/internal.h |  16 ++++++
 kernel/printk/printk.c   | 115 +++++++++++++++++++++++++++------------
 2 files changed, 96 insertions(+), 35 deletions(-)

diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
index 6080d289a342..c9bb0cd86372 100644
--- a/kernel/printk/internal.h
+++ b/kernel/printk/internal.h
@@ -92,3 +92,19 @@ struct printk_buffers {
 	char	outbuf[CONSOLE_EXT_LOG_MAX];
 	char	scratchbuf[LOG_LINE_MAX];
 };
+
+/**
+ * struct printk_message - Container for a prepared printk message.
+ * @pbufs:	printk buffers used to prepare the message.
+ * @outbuf_len:	The length of prepared text in @pbufs->outbuf to output. This
+ *		does not count the terminator. A value of 0 means there is
+ *		nothing to output and this record should be skipped.
+ * @seq:	The sequence number of the record used for @pbufs->outbuf.
+ * @dropped:	The number of dropped records from reading @seq.
+ */
+struct printk_message {
+	struct printk_buffers	*pbufs;
+	unsigned int		outbuf_len;
+	u64			seq;
+	unsigned long		dropped;
+};
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index bc5d4574c459..6e2a6d5548e9 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2725,35 +2725,35 @@ static void __console_unlock(void)
 }
 
 /*
- * Print one record for the given console. The record printed is whatever
- * record is the next available record for the given console.
+ * Read and format the specified record (or a later record if the specified
+ * record is not available).
  *
- * @handover will be set to true if a printk waiter has taken over the
- * console_lock, in which case the caller is no longer holding both the
- * console_lock and the SRCU read lock. Otherwise it is set to false.
+ * @pmsg will contain the formatted result. @pmsg->pbufs must point to a
+ * struct printk_buffers.
  *
- * @cookie is the cookie from the SRCU read lock.
+ * @seq is the record to read and format. If it is not available, the next
+ * valid record is read.
  *
- * Returns false if the given console has no next record to print, otherwise
- * true.
+ * @is_extended specifies if the message should be formatted for extended
+ * console output.
  *
- * Requires the console_lock and the SRCU read lock.
+ * Returns false if no record is available. Otherwise true and all fields
+ * of @pmsg are valid. (See the documentation of struct printk_message
+ * for information about the @pmsg fields.)
  */
-static bool console_emit_next_record(struct console *con, bool *handover, int cookie)
+static bool printk_get_next_message(struct printk_message *pmsg, u64 seq,
+				    bool is_extended)
 {
-	static char dropped_text[DROPPED_TEXT_MAX];
-	static struct printk_buffers pbufs;
 	static int panic_console_dropped;
 
-	bool is_extended = console_srcu_read_flags(con) & CON_EXTENDED;
-	const size_t scratchbuf_sz = sizeof(pbufs.scratchbuf);
-	const size_t outbuf_sz = sizeof(pbufs.outbuf);
-	char *scratchbuf = &pbufs.scratchbuf[0];
-	char *outbuf = &pbufs.outbuf[0];
+	struct printk_buffers *pbufs = pmsg->pbufs;
+	const size_t scratchbuf_sz = sizeof(pbufs->scratchbuf);
+	const size_t outbuf_sz = sizeof(pbufs->outbuf);
+	char *scratchbuf = &pbufs->scratchbuf[0];
+	char *outbuf = &pbufs->outbuf[0];
 	struct printk_info info;
 	struct printk_record r;
-	unsigned long flags;
-	size_t len;
+	size_t len = 0;
 
 	/*
 	 * Formatting extended messages requires a separate buffer, so use the
@@ -2767,25 +2767,26 @@ static bool console_emit_next_record(struct console *con, bool *handover, int co
 	else
 		prb_rec_init_rd(&r, &info, outbuf, outbuf_sz);
 
-	*handover = false;
-
-	if (!prb_read_valid(prb, con->seq, &r))
+	if (!prb_read_valid(prb, seq, &r))
 		return false;
 
-	if (con->seq != r.info->seq) {
-		con->dropped += r.info->seq - con->seq;
-		con->seq = r.info->seq;
-		if (panic_in_progress() && panic_console_dropped++ > 10) {
-			suppress_panic_printk = 1;
-			pr_warn_once("Too many dropped messages. Suppress messages on non-panic CPUs to prevent livelock.\n");
-		}
+	pmsg->seq = r.info->seq;
+	pmsg->dropped = r.info->seq - seq;
+
+	/*
+	 * Check for dropped messages in panic here so that printk
+	 * suppression can occur as early as possible if necessary.
+	 */
+	if (pmsg->dropped &&
+	    panic_in_progress() &&
+	    panic_console_dropped++ > 10) {
+		suppress_panic_printk = 1;
+		pr_warn_once("Too many dropped messages. Suppress messages on non-panic CPUs to prevent livelock.\n");
 	}
 
 	/* Skip record that has level above the console loglevel. */
-	if (suppress_message_printing(r.info->level)) {
-		con->seq++;
-		goto skip;
-	}
+	if (suppress_message_printing(r.info->level))
+		goto out;
 
 	if (is_extended) {
 		len = info_print_ext_header(outbuf, outbuf_sz, r.info);
@@ -2794,6 +2795,50 @@ static bool console_emit_next_record(struct console *con, bool *handover, int co
 	} else {
 		len = record_print_text(&r, console_msg_format & MSG_FORMAT_SYSLOG, printk_time);
 	}
+out:
+	pmsg->outbuf_len = len;
+	return true;
+}
+
+/*
+ * Print one record for the given console. The record printed is whatever
+ * record is the next available record for the given console.
+ *
+ * @handover will be set to true if a printk waiter has taken over the
+ * console_lock, in which case the caller is no longer holding both the
+ * console_lock and the SRCU read lock. Otherwise it is set to false.
+ *
+ * @cookie is the cookie from the SRCU read lock.
+ *
+ * Returns false if the given console has no next record to print, otherwise
+ * true.
+ *
+ * Requires the console_lock and the SRCU read lock.
+ */
+static bool console_emit_next_record(struct console *con, bool *handover, int cookie)
+{
+	static char dropped_text[DROPPED_TEXT_MAX];
+	static struct printk_buffers pbufs;
+
+	bool is_extended = console_srcu_read_flags(con) & CON_EXTENDED;
+	char *outbuf = &pbufs.outbuf[0];
+	struct printk_message pmsg = {
+		.pbufs = &pbufs,
+	};
+	unsigned long flags;
+
+	*handover = false;
+
+	if (!printk_get_next_message(&pmsg, con->seq, is_extended))
+		return false;
+
+	con->dropped += pmsg.dropped;
+
+	/* Skip messages of formatted length 0. */
+	if (pmsg.outbuf_len == 0) {
+		con->seq = pmsg.seq + 1;
+		goto skip;
+	}
 
 	/*
 	 * While actively printing out messages, if another printk()
@@ -2809,11 +2854,11 @@ static bool console_emit_next_record(struct console *con, bool *handover, int co
 	console_lock_spinning_enable();
 
 	stop_critical_timings();	/* don't trace print latency */
-	call_console_driver(con, outbuf, len,
+	call_console_driver(con, outbuf, pmsg.outbuf_len,
 			    is_extended ? NULL : dropped_text);
 	start_critical_timings();
 
-	con->seq++;
+	con->seq = pmsg.seq + 1;
 
 	*handover = console_lock_spinning_disable_and_check(cookie);
 	printk_safe_exit_irqrestore(flags);
-- 
2.30.2


^ permalink raw reply related	[flat|nested] 22+ messages in thread

* [PATCH printk v4 6/8] printk: introduce console_prepend_dropped() for dropped messages
  2023-01-05 10:37 [PATCH printk v4 0/8] printk: cleanup buffer handling John Ogness
                   ` (4 preceding siblings ...)
  2023-01-05 10:37 ` [PATCH printk v4 5/8] printk: introduce printk_get_next_message() and printk_message John Ogness
@ 2023-01-05 10:37 ` John Ogness
  2023-01-05 16:17   ` Petr Mladek
  2023-01-05 10:37 ` [PATCH printk v4 7/8] printk: use printk_buffers for devkmsg John Ogness
                   ` (2 subsequent siblings)
  8 siblings, 1 reply; 22+ messages in thread
From: John Ogness @ 2023-01-05 10:37 UTC (permalink / raw)
  To: Petr Mladek
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner, linux-kernel

Currently "dropped messages" are separately printed immediately
before printing the printk message. Since normal consoles are
now using an output buffer that is much larger than previously,
the "dropped message" could be prepended to the printk message
and then output everything in a single write() call.

Introduce a helper function console_prepend_dropped() to prepend
an existing message with a "dropped message". This simplifies
the code by allowing all message formatting to be handled
together and then only requires a single write() call to output
the full message. And since this helper does not require any
locking, it can be used in the future for other console printing
contexts as well.

Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
 kernel/printk/internal.h |  4 --
 kernel/printk/printk.c   | 86 ++++++++++++++++++++++++++--------------
 2 files changed, 57 insertions(+), 33 deletions(-)

diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
index c9bb0cd86372..72df730597f1 100644
--- a/kernel/printk/internal.h
+++ b/kernel/printk/internal.h
@@ -26,9 +26,6 @@ int devkmsg_sysctl_set_loglvl(struct ctl_table *table, int write,
 /* the maximum size of a formatted extended record */
 #define CONSOLE_EXT_LOG_MAX	8192
 
-/* the maximum size for a dropped text message */
-#define DROPPED_TEXT_MAX	64
-
 /* the maximum size allowed to be reserved for a record */
 #define LOG_LINE_MAX		(CONSOLE_LOG_MAX - PREFIX_MAX)
 
@@ -69,7 +66,6 @@ u16 printk_parse_prefix(const char *text, int *level,
 #define PREFIX_MAX		0
 #define CONSOLE_LOG_MAX		0
 #define CONSOLE_EXT_LOG_MAX	0
-#define DROPPED_TEXT_MAX	0
 #define LOG_LINE_MAX		0
 
 /*
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 6e2a6d5548e9..4fb7d29fb05d 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1995,27 +1995,6 @@ static int console_trylock_spinning(void)
 	return 1;
 }
 
-/*
- * Call the specified console driver, asking it to write out the specified
- * text and length. If @dropped_text is non-NULL and any records have been
- * dropped, a dropped message will be written out first.
- */
-static void call_console_driver(struct console *con, const char *text, size_t len,
-				char *dropped_text)
-{
-	size_t dropped_len;
-
-	if (con->dropped && dropped_text) {
-		dropped_len = snprintf(dropped_text, DROPPED_TEXT_MAX,
-				       "** %lu printk messages dropped **\n",
-				       con->dropped);
-		con->dropped = 0;
-		con->write(con, dropped_text, dropped_len);
-	}
-
-	con->write(con, text, len);
-}
-
 /*
  * Recursion is tracked separately on each CPU. If NMIs are supported, an
  * additional NMI context per CPU is also separately tracked. Until per-CPU
@@ -2395,10 +2374,6 @@ static ssize_t msg_print_ext_body(char *buf, size_t size,
 				  struct dev_printk_info *dev_info) { return 0; }
 static void console_lock_spinning_enable(void) { }
 static int console_lock_spinning_disable_and_check(int cookie) { return 0; }
-static void call_console_driver(struct console *con, const char *text, size_t len,
-				char *dropped_text)
-{
-}
 static bool suppress_message_printing(int level) { return false; }
 static bool pr_flush(int timeout_ms, bool reset_on_progress) { return true; }
 static bool __pr_flush(struct console *con, int timeout_ms, bool reset_on_progress) { return true; }
@@ -2724,6 +2699,52 @@ static void __console_unlock(void)
 	up_console_sem();
 }
 
+/*
+ * Prepend the message in @pmsg->pbufs->outbuf with a "dropped message". This
+ * is achieved by shifting the existing message over and inserting the dropped
+ * message.
+ *
+ * @pmsg is the printk message to prepend.
+ *
+ * @dropped is the dropped count to report in the dropped message.
+ *
+ * If the message text in @pmsg->pbufs->outbuf does not have enough space for
+ * the dropped message, the message text will be sufficiently truncated.
+ *
+ * If @pmsg->pbufs->outbuf is modified, @pmsg->outbuf_len is updated.
+ */
+static void console_prepend_dropped(struct printk_message *pmsg, unsigned long dropped)
+{
+	struct printk_buffers *pbufs = pmsg->pbufs;
+	const size_t scratchbuf_sz = sizeof(pbufs->scratchbuf);
+	const size_t outbuf_sz = sizeof(pbufs->outbuf);
+	char *scratchbuf = &pbufs->scratchbuf[0];
+	char *outbuf = &pbufs->outbuf[0];
+	size_t len;
+
+	len = snprintf(scratchbuf, scratchbuf_sz,
+		       "** %lu printk messages dropped **\n", dropped);
+
+	/*
+	 * Make sure outbuf is sufficiently large before prepending.
+	 * Keep at least the prefix when the message must be truncated.
+	 * It is a rather theoretical problem when someone tries to
+	 * use a minimalist buffer.
+	 */
+	if (WARN_ON_ONCE(len + PREFIX_MAX >= outbuf_sz))
+		return;
+
+	if (pmsg->outbuf_len + len >= outbuf_sz) {
+		/* Truncate the message, but keep it terminated. */
+		pmsg->outbuf_len = outbuf_sz - (len + 1);
+		outbuf[pmsg->outbuf_len] = 0;
+	}
+
+	memmove(outbuf + len, outbuf, pmsg->outbuf_len + 1);
+	memcpy(outbuf, scratchbuf, len);
+	pmsg->outbuf_len += len;
+}
+
 /*
  * Read and format the specified record (or a later record if the specified
  * record is not available).
@@ -2817,7 +2838,6 @@ static bool printk_get_next_message(struct printk_message *pmsg, u64 seq,
  */
 static bool console_emit_next_record(struct console *con, bool *handover, int cookie)
 {
-	static char dropped_text[DROPPED_TEXT_MAX];
 	static struct printk_buffers pbufs;
 
 	bool is_extended = console_srcu_read_flags(con) & CON_EXTENDED;
@@ -2840,6 +2860,11 @@ static bool console_emit_next_record(struct console *con, bool *handover, int co
 		goto skip;
 	}
 
+	if (con->dropped && !is_extended) {
+		console_prepend_dropped(&pmsg, con->dropped);
+		con->dropped = 0;
+	}
+
 	/*
 	 * While actively printing out messages, if another printk()
 	 * were to occur on another CPU, it may wait for this one to
@@ -2853,9 +2878,12 @@ static bool console_emit_next_record(struct console *con, bool *handover, int co
 	printk_safe_enter_irqsave(flags);
 	console_lock_spinning_enable();
 
-	stop_critical_timings();	/* don't trace print latency */
-	call_console_driver(con, outbuf, pmsg.outbuf_len,
-			    is_extended ? NULL : dropped_text);
+	/* Do not trace print latency. */
+	stop_critical_timings();
+
+	/* Write everything out to the hardware. */
+	con->write(con, outbuf, pmsg.outbuf_len);
+
 	start_critical_timings();
 
 	con->seq = pmsg.seq + 1;
-- 
2.30.2


^ permalink raw reply related	[flat|nested] 22+ messages in thread

* [PATCH printk v4 7/8] printk: use printk_buffers for devkmsg
  2023-01-05 10:37 [PATCH printk v4 0/8] printk: cleanup buffer handling John Ogness
                   ` (5 preceding siblings ...)
  2023-01-05 10:37 ` [PATCH printk v4 6/8] printk: introduce console_prepend_dropped() for dropped messages John Ogness
@ 2023-01-05 10:37 ` John Ogness
  2023-01-05 12:14   ` John Ogness
  2023-01-05 10:37 ` [PATCH printk v4 8/8] printk: adjust string limit macros John Ogness
  2023-01-06 11:21 ` [PATCH printk v4 0/8] printk: cleanup buffer handling Petr Mladek
  8 siblings, 1 reply; 22+ messages in thread
From: John Ogness @ 2023-01-05 10:37 UTC (permalink / raw)
  To: Petr Mladek
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner, linux-kernel

Replace the individual @text_buf and @buf buffers in struct
devkmsg_user with a struct printk_buffers. This reduces the number
of buffers to keep track of. Also, since @text_buf is only used for
ringbuffer reading and @buf is only used for output, it maps
perfectly to the purpose and fields of struct printk_buffers.

As a side-effect, @text_buf was 8kB large, even though it only
needed to be the max size of a ringbuffer record. By switching to
struct printk_buffers, ~7kB less memory is allocated when opening
/dev/kmsg.

And since struct printk_buffers will be used now, reduce duplicate
code by calling printk_get_next_message() to handle the record
reading and formatting.

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

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 4fb7d29fb05d..e28a3736a399 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -695,15 +695,16 @@ static ssize_t msg_print_ext_body(char *buf, size_t size,
 	return len;
 }
 
+static bool printk_get_next_message(struct printk_message *pmsg, u64 seq, bool is_extended);
+
 /* /dev/kmsg - userspace message inject/listen interface */
 struct devkmsg_user {
 	atomic64_t seq;
 	struct ratelimit_state rs;
 	struct mutex lock;
-	char buf[CONSOLE_EXT_LOG_MAX];
 
+	struct printk_buffers pbufs;
 	struct printk_info info;
-	char text_buf[CONSOLE_EXT_LOG_MAX];
 	struct printk_record record;
 };
 
@@ -787,7 +788,10 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
 {
 	struct devkmsg_user *user = file->private_data;
 	struct printk_record *r = &user->record;
-	size_t len;
+	char *outbuf = &user->pbufs.outbuf[0];
+	struct printk_message pmsg = {
+		.pbufs = &user->pbufs,
+	};
 	ssize_t ret;
 
 	if (!user)
@@ -797,7 +801,7 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
 	if (ret)
 		return ret;
 
-	if (!prb_read_valid(prb, atomic64_read(&user->seq), r)) {
+	if (!printk_get_next_message(&pmsg, atomic64_read(&user->seq), true)) {
 		if (file->f_flags & O_NONBLOCK) {
 			ret = -EAGAIN;
 			goto out;
@@ -820,30 +824,25 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
 			goto out;
 	}
 
-	if (r->info->seq != atomic64_read(&user->seq)) {
+	if (pmsg.dropped) {
 		/* our last seen message is gone, return error and reset */
-		atomic64_set(&user->seq, r->info->seq);
+		atomic64_set(&user->seq, pmsg.seq);
 		ret = -EPIPE;
 		goto out;
 	}
 
-	len = info_print_ext_header(user->buf, sizeof(user->buf), r->info);
-	len += msg_print_ext_body(user->buf + len, sizeof(user->buf) - len,
-				  &r->text_buf[0], r->info->text_len,
-				  &r->info->dev_info);
-
-	atomic64_set(&user->seq, r->info->seq + 1);
+	atomic64_set(&user->seq, pmsg.seq + 1);
 
-	if (len > count) {
+	if (pmsg.outbuf_len > count) {
 		ret = -EINVAL;
 		goto out;
 	}
 
-	if (copy_to_user(buf, user->buf, len)) {
+	if (copy_to_user(buf, outbuf, pmsg.outbuf_len)) {
 		ret = -EFAULT;
 		goto out;
 	}
-	ret = len;
+	ret = pmsg.outbuf_len;
 out:
 	mutex_unlock(&user->lock);
 	return ret;
@@ -937,9 +936,6 @@ static int devkmsg_open(struct inode *inode, struct file *file)
 
 	mutex_init(&user->lock);
 
-	prb_rec_init_rd(&user->record, &user->info,
-			&user->text_buf[0], sizeof(user->text_buf));
-
 	atomic64_set(&user->seq, prb_first_valid_seq(prb));
 
 	file->private_data = user;
-- 
2.30.2


^ permalink raw reply related	[flat|nested] 22+ messages in thread

* [PATCH printk v4 8/8] printk: adjust string limit macros
  2023-01-05 10:37 [PATCH printk v4 0/8] printk: cleanup buffer handling John Ogness
                   ` (6 preceding siblings ...)
  2023-01-05 10:37 ` [PATCH printk v4 7/8] printk: use printk_buffers for devkmsg John Ogness
@ 2023-01-05 10:37 ` John Ogness
  2023-01-06 11:11   ` Petr Mladek
  2023-01-06 11:21 ` [PATCH printk v4 0/8] printk: cleanup buffer handling Petr Mladek
  8 siblings, 1 reply; 22+ messages in thread
From: John Ogness @ 2023-01-05 10:37 UTC (permalink / raw)
  To: Petr Mladek
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner, linux-kernel

The various internal size limit macros have names and/or values that
do not fit well to their current usage.

Rename the macros so that their purpose is clear and, if needed,
provide a more appropriate value. In general, the new macros and
values will lead to less memory usage. The new macros are...

PRINTK_MESSAGE_MAX:

This is the maximum size for a formatted message on a console,
devkmsg, or syslog. It does not matter which format the message has
(normal or extended). It replaces the use of CONSOLE_EXT_LOG_MAX for
console and devkmsg. It replaces the use of CONSOLE_LOG_MAX for
syslog.

Historically, normal messages have been allowed to print up to 1kB,
whereas extended messages have been allowed to print up to 8kB.
However, the difference in lengths of these message types is not
significant and in multi-line records, normal messages are probably
larger. Also, because 1kB is only slightly above the allowed record
size, multi-line normal messages could be easily truncated during
formatting.

This new macro should be significantly larger than the allowed
record size to allow sufficient space for extended or multi-line
prefix text. A value of 2kB should be plenty of space. For normal
messages this represents a doubling of the historically allowed
amount. For extended messages it reduces the excessive 8kB size,
thus reducing memory usage needed for message formatting.

PRINTK_PREFIX_MAX:

This is the maximum size allowed for a record prefix (used by
console and syslog). It replaces PREFIX_MAX. The value is left
unchanged.

PRINTKRB_RECORD_MAX:

This is the maximum size allowed to be reserved for a record in the
ringbuffer. It is used by all readers and writers with the printk
ringbuffer. It replaces LOG_LINE_MAX.

Previously this was set to "1kB - PREFIX_MAX", which makes some
sense if 1kB is the limit for normal message output and prefixes are
enabled. However, with the allowance of larger output and the
existence of multi-line records, the value is rather bizarre.

Round the value up to 1kB.

Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
 kernel/printk/internal.h | 27 +++++++++++++--------------
 kernel/printk/printk.c   | 24 ++++++++++++------------
 2 files changed, 25 insertions(+), 26 deletions(-)

diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
index 72df730597f1..2a17704136f1 100644
--- a/kernel/printk/internal.h
+++ b/kernel/printk/internal.h
@@ -15,19 +15,19 @@ int devkmsg_sysctl_set_loglvl(struct ctl_table *table, int write,
 #ifdef CONFIG_PRINTK
 
 #ifdef CONFIG_PRINTK_CALLER
-#define PREFIX_MAX		48
+#define PRINTK_PREFIX_MAX	48
 #else
-#define PREFIX_MAX		32
+#define PRINTK_PREFIX_MAX	32
 #endif
 
-/* the maximum size of a formatted record (i.e. with prefix added per line) */
-#define CONSOLE_LOG_MAX		1024
-
-/* the maximum size of a formatted extended record */
-#define CONSOLE_EXT_LOG_MAX	8192
+/*
+ * the maximum size of a formatted record (i.e. with prefix added
+ * per line and dropped messages or in extended message format)
+ */
+#define PRINTK_MESSAGE_MAX	2048
 
 /* the maximum size allowed to be reserved for a record */
-#define LOG_LINE_MAX		(CONSOLE_LOG_MAX - PREFIX_MAX)
+#define PRINTKRB_RECORD_MAX	1024
 
 /* Flags for a single printk record. */
 enum printk_info_flags {
@@ -63,10 +63,9 @@ u16 printk_parse_prefix(const char *text, int *level,
 			enum printk_info_flags *flags);
 #else
 
-#define PREFIX_MAX		0
-#define CONSOLE_LOG_MAX		0
-#define CONSOLE_EXT_LOG_MAX	0
-#define LOG_LINE_MAX		0
+#define PRINTK_PREFIX_MAX	0
+#define PRINTK_MESSAGE_MAX	0
+#define PRINTKRB_RECORD_MAX	0
 
 /*
  * In !PRINTK builds we still export console_sem
@@ -85,8 +84,8 @@ static inline bool printk_percpu_data_ready(void) { return false; }
  * @scratchbuf:	Used as temporary ringbuffer reading and string-print space.
  */
 struct printk_buffers {
-	char	outbuf[CONSOLE_EXT_LOG_MAX];
-	char	scratchbuf[LOG_LINE_MAX];
+	char	outbuf[PRINTK_MESSAGE_MAX];
+	char	scratchbuf[PRINTKRB_RECORD_MAX];
 };
 
 /**
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index e28a3736a399..e21bfcd1b1ef 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -731,7 +731,7 @@ static ssize_t devkmsg_write(struct kiocb *iocb, struct iov_iter *from)
 	size_t len = iov_iter_count(from);
 	ssize_t ret = len;
 
-	if (!user || len > LOG_LINE_MAX)
+	if (!user || len > PRINTKRB_RECORD_MAX)
 		return -EINVAL;
 
 	/* Ignore when user logging is disabled. */
@@ -1130,7 +1130,7 @@ static unsigned int __init add_to_rb(struct printk_ringbuffer *rb,
 	return prb_record_text_space(&e);
 }
 
-static char setup_text_buf[LOG_LINE_MAX] __initdata;
+static char setup_text_buf[PRINTKRB_RECORD_MAX] __initdata;
 
 void __init setup_log_buf(int early)
 {
@@ -1396,7 +1396,7 @@ static size_t record_print_text(struct printk_record *r, bool syslog,
 	size_t text_len = r->info->text_len;
 	size_t buf_size = r->text_buf_size;
 	char *text = r->text_buf;
-	char prefix[PREFIX_MAX];
+	char prefix[PRINTK_PREFIX_MAX];
 	bool truncated = false;
 	size_t prefix_len;
 	size_t line_len;
@@ -1495,7 +1495,7 @@ static size_t get_record_print_text_size(struct printk_info *info,
 					 unsigned int line_count,
 					 bool syslog, bool time)
 {
-	char prefix[PREFIX_MAX];
+	char prefix[PRINTK_PREFIX_MAX];
 	size_t prefix_len;
 
 	prefix_len = info_print_prefix(info, syslog, time, prefix);
@@ -1561,11 +1561,11 @@ static int syslog_print(char __user *buf, int size)
 	int len = 0;
 	u64 seq;
 
-	text = kmalloc(CONSOLE_LOG_MAX, GFP_KERNEL);
+	text = kmalloc(PRINTK_MESSAGE_MAX, GFP_KERNEL);
 	if (!text)
 		return -ENOMEM;
 
-	prb_rec_init_rd(&r, &info, text, CONSOLE_LOG_MAX);
+	prb_rec_init_rd(&r, &info, text, PRINTK_MESSAGE_MAX);
 
 	mutex_lock(&syslog_lock);
 
@@ -1666,7 +1666,7 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
 	u64 seq;
 	bool time;
 
-	text = kmalloc(CONSOLE_LOG_MAX, GFP_KERNEL);
+	text = kmalloc(PRINTK_MESSAGE_MAX, GFP_KERNEL);
 	if (!text)
 		return -ENOMEM;
 
@@ -1678,7 +1678,7 @@ static int syslog_print_all(char __user *buf, int size, bool clear)
 	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);
+	prb_rec_init_rd(&r, &info, text, PRINTK_MESSAGE_MAX);
 
 	len = 0;
 	prb_for_each_record(seq, prb, seq, &r) {
@@ -2201,8 +2201,8 @@ int vprintk_store(int facility, int level,
 	reserve_size = vsnprintf(&prefix_buf[0], sizeof(prefix_buf), fmt, args2) + 1;
 	va_end(args2);
 
-	if (reserve_size > LOG_LINE_MAX)
-		reserve_size = LOG_LINE_MAX;
+	if (reserve_size > PRINTKRB_RECORD_MAX)
+		reserve_size = PRINTKRB_RECORD_MAX;
 
 	/* Extract log level or control flags. */
 	if (facility == 0)
@@ -2216,7 +2216,7 @@ int vprintk_store(int facility, int level,
 
 	if (flags & LOG_CONT) {
 		prb_rec_init_wr(&r, reserve_size);
-		if (prb_reserve_in_last(&e, prb, &r, caller_id, LOG_LINE_MAX)) {
+		if (prb_reserve_in_last(&e, prb, &r, caller_id, PRINTKRB_RECORD_MAX)) {
 			text_len = printk_sprint(&r.text_buf[r.info->text_len], reserve_size,
 						 facility, &flags, fmt, args);
 			r.info->text_len += text_len;
@@ -2727,7 +2727,7 @@ static void console_prepend_dropped(struct printk_message *pmsg, unsigned long d
 	 * It is a rather theoretical problem when someone tries to
 	 * use a minimalist buffer.
 	 */
-	if (WARN_ON_ONCE(len + PREFIX_MAX >= outbuf_sz))
+	if (WARN_ON_ONCE(len + PRINTK_PREFIX_MAX >= outbuf_sz))
 		return;
 
 	if (pmsg->outbuf_len + len >= outbuf_sz) {
-- 
2.30.2


^ permalink raw reply related	[flat|nested] 22+ messages in thread

* Re: [PATCH printk v4 7/8] printk: use printk_buffers for devkmsg
  2023-01-05 10:37 ` [PATCH printk v4 7/8] printk: use printk_buffers for devkmsg John Ogness
@ 2023-01-05 12:14   ` John Ogness
  2023-01-05 12:16     ` [PATCH printk v4 7/8 v2] " John Ogness
  0 siblings, 1 reply; 22+ messages in thread
From: John Ogness @ 2023-01-05 12:14 UTC (permalink / raw)
  To: Petr Mladek
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner, linux-kernel

On 2023-01-05, John Ogness <john.ogness@linutronix.de> wrote:
>  /* /dev/kmsg - userspace message inject/listen interface */
>  struct devkmsg_user {
>  	atomic64_t seq;
>  	struct ratelimit_state rs;
>  	struct mutex lock;
> -	char buf[CONSOLE_EXT_LOG_MAX];
>  
> +	struct printk_buffers pbufs;
>  	struct printk_info info;
> -	char text_buf[CONSOLE_EXT_LOG_MAX];
>  	struct printk_record record;
>  };

There is also no need for the printk_info and printk_record
structs. printk_get_next_message() uses its own on the stack.

> @@ -797,7 +801,7 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
>  	if (ret)
>  		return ret;
>  
> -	if (!prb_read_valid(prb, atomic64_read(&user->seq), r)) {
> +	if (!printk_get_next_message(&pmsg, atomic64_read(&user->seq), true)) {

This needs to be a while loop because printk_get_next_message() should
be the only function reading from the ringbuffer. The
wait_event_interruptible() in this loop should just wait for the
existence of the new record. It should not be the one reading it.

I will reply to this message with the correct patch to replace this
patch.

John Ogness

^ permalink raw reply	[flat|nested] 22+ messages in thread

* [PATCH printk v4 7/8 v2] printk: use printk_buffers for devkmsg
  2023-01-05 12:14   ` John Ogness
@ 2023-01-05 12:16     ` John Ogness
  2023-01-06 10:39       ` Petr Mladek
  0 siblings, 1 reply; 22+ messages in thread
From: John Ogness @ 2023-01-05 12:16 UTC (permalink / raw)
  To: Petr Mladek
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner, linux-kernel

Replace the buffers in struct devkmsg_user with a struct
printk_buffers. This reduces the number of buffers to track.

As a side-effect, @text_buf was 8kB large, even though it only
needed to be the max size of a ringbuffer record. By switching to
struct printk_buffers, ~7kB less memory is allocated when opening
/dev/kmsg.

And since struct printk_buffers will be used now, reduce duplicate
code by calling printk_get_next_message() to handle the record
reading and formatting.

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

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 4fb7d29fb05d..32996b0c5d03 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -695,16 +695,14 @@ static ssize_t msg_print_ext_body(char *buf, size_t size,
 	return len;
 }
 
+static bool printk_get_next_message(struct printk_message *pmsg, u64 seq, bool is_extended);
+
 /* /dev/kmsg - userspace message inject/listen interface */
 struct devkmsg_user {
 	atomic64_t seq;
 	struct ratelimit_state rs;
 	struct mutex lock;
-	char buf[CONSOLE_EXT_LOG_MAX];
-
-	struct printk_info info;
-	char text_buf[CONSOLE_EXT_LOG_MAX];
-	struct printk_record record;
+	struct printk_buffers pbufs;
 };
 
 static __printf(3, 4) __cold
@@ -786,8 +784,10 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
 			    size_t count, loff_t *ppos)
 {
 	struct devkmsg_user *user = file->private_data;
-	struct printk_record *r = &user->record;
-	size_t len;
+	char *outbuf = &user->pbufs.outbuf[0];
+	struct printk_message pmsg = {
+		.pbufs = &user->pbufs,
+	};
 	ssize_t ret;
 
 	if (!user)
@@ -797,7 +797,7 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
 	if (ret)
 		return ret;
 
-	if (!prb_read_valid(prb, atomic64_read(&user->seq), r)) {
+	while (!printk_get_next_message(&pmsg, atomic64_read(&user->seq), true)) {
 		if (file->f_flags & O_NONBLOCK) {
 			ret = -EAGAIN;
 			goto out;
@@ -814,36 +814,31 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
 		 * This pairs with __wake_up_klogd:A.
 		 */
 		ret = wait_event_interruptible(log_wait,
-				prb_read_valid(prb,
-					atomic64_read(&user->seq), r)); /* LMM(devkmsg_read:A) */
+					       prb_read_valid(prb, atomic64_read(&user->seq),
+							      NULL)); /* LMM(devkmsg_read:A) */
 		if (ret)
 			goto out;
 	}
 
-	if (r->info->seq != atomic64_read(&user->seq)) {
+	if (pmsg.dropped) {
 		/* our last seen message is gone, return error and reset */
-		atomic64_set(&user->seq, r->info->seq);
+		atomic64_set(&user->seq, pmsg.seq);
 		ret = -EPIPE;
 		goto out;
 	}
 
-	len = info_print_ext_header(user->buf, sizeof(user->buf), r->info);
-	len += msg_print_ext_body(user->buf + len, sizeof(user->buf) - len,
-				  &r->text_buf[0], r->info->text_len,
-				  &r->info->dev_info);
+	atomic64_set(&user->seq, pmsg.seq + 1);
 
-	atomic64_set(&user->seq, r->info->seq + 1);
-
-	if (len > count) {
+	if (pmsg.outbuf_len > count) {
 		ret = -EINVAL;
 		goto out;
 	}
 
-	if (copy_to_user(buf, user->buf, len)) {
+	if (copy_to_user(buf, outbuf, pmsg.outbuf_len)) {
 		ret = -EFAULT;
 		goto out;
 	}
-	ret = len;
+	ret = pmsg.outbuf_len;
 out:
 	mutex_unlock(&user->lock);
 	return ret;
@@ -937,9 +932,6 @@ static int devkmsg_open(struct inode *inode, struct file *file)
 
 	mutex_init(&user->lock);
 
-	prb_rec_init_rd(&user->record, &user->info,
-			&user->text_buf[0], sizeof(user->text_buf));
-
 	atomic64_set(&user->seq, prb_first_valid_seq(prb));
 
 	file->private_data = user;
-- 
2.30.2

^ permalink raw reply related	[flat|nested] 22+ messages in thread

* Re: [PATCH printk v4 1/8] printk: move size limit macros into internal.h
  2023-01-05 10:37 ` [PATCH printk v4 1/8] printk: move size limit macros into internal.h John Ogness
@ 2023-01-05 14:48   ` Petr Mladek
  0 siblings, 0 replies; 22+ messages in thread
From: Petr Mladek @ 2023-01-05 14:48 UTC (permalink / raw)
  To: John Ogness
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner, linux-kernel

On Thu 2023-01-05 11:43:28, John Ogness wrote:
> The size limit macros are located further down in printk.c and
> behind ifdef conditionals. This complicates their usage for
> upcoming changes. Move the macros into internal.h so that they
> are still invisible outside of printk, but easily accessible
> for printk.
> 
> Also, the maximum size of formatted extended messages does not
> need to be known by any code outside of printk, so move it to
> internal.h as well. And like CONSOLE_LOG_MAX, for !CONFIG_PRINTK
> set CONSOLE_EXT_LOG_MAX to 0 to reduce the static memory
> footprint.
> 
> Signed-off-by: John Ogness <john.ogness@linutronix.de>

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

Best Regards,
Petr

^ permalink raw reply	[flat|nested] 22+ messages in thread

* Re: [PATCH printk v4 4/8] printk: introduce struct printk_buffers
  2023-01-05 10:37 ` [PATCH printk v4 4/8] printk: introduce struct printk_buffers John Ogness
@ 2023-01-05 15:06   ` Petr Mladek
  0 siblings, 0 replies; 22+ messages in thread
From: Petr Mladek @ 2023-01-05 15:06 UTC (permalink / raw)
  To: John Ogness
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner, linux-kernel

On Thu 2023-01-05 11:43:31, John Ogness wrote:
> Introduce a new struct printk_buffers to contain all the buffers
> needed to read and format a printk message for output. Putting the
> buffers inside a struct reduces the number of buffer pointers that
> need to be tracked. Also, it allows usage of the sizeof() macro for
> the buffer sizes, rather than expecting certain sized buffers being
> passed in.
> 
> Note that since the output buffer for normal consoles is now
> CONSOLE_EXT_LOG_MAX instead of CONSOLE_LOG_MAX, multi-line
> messages that may have been previously truncated will now be
> printed in full. This should be considered a feature and not a bug
> since the CONSOLE_LOG_MAX restriction was about limiting static
> buffer usage rather than limiting printed text.
> 
> Signed-off-by: John Ogness <john.ogness@linutronix.de>

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

Best Regards,
Petr

^ permalink raw reply	[flat|nested] 22+ messages in thread

* Re: [PATCH printk v4 5/8] printk: introduce printk_get_next_message() and printk_message
  2023-01-05 10:37 ` [PATCH printk v4 5/8] printk: introduce printk_get_next_message() and printk_message John Ogness
@ 2023-01-05 15:24   ` Petr Mladek
  0 siblings, 0 replies; 22+ messages in thread
From: Petr Mladek @ 2023-01-05 15:24 UTC (permalink / raw)
  To: John Ogness
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner, linux-kernel

On Thu 2023-01-05 11:43:32, John Ogness wrote:
> Code for performing the console output is intermixed with code that
> is formatting the output for that console. Introduce a new helper
> function printk_get_next_message() to handle the reading and
> formatting of the printk text. The helper does not require any
> locking so that in the future it can be used for other printing
> contexts as well.
> 
> This also introduces a new struct printk_message to wrap the struct
> printk_buffers, adding metadata about its contents. This allows
> users of printk_get_next_message() to receive all relevant
> information about the message that was read and formatted.
> 
> Why is struct printk_message a wrapper struct?
> 
> It is intentional that a wrapper struct is introduced instead of
> adding the metadata directly to struct printk_buffers. The upcoming
> atomic consoles support multiple printing contexts per CPU. This
> means that while a CPU is formatting a message, it can be
> interrupted and the interrupting context may also format a (possibly
> different) message. Since the printk buffers are rather large,
> there will only be one struct printk_buffers per CPU and it must be
> shared by the possible contexts of that CPU.
> 
> If the metadata was part of struct printk_buffers, interrupting
> contexts would clobber the metadata being prepared by the
> interrupted context. This could be handled by robustifying the
> message formatting functions to cope with metadata unexpectedly
> changing. However, this would require significant amounts of extra
> data copying, also adding significant complexity to the code.
> 
> Instead, the metadata can live on the stack of the formatting
> context and the message formatting functions do not need to be
> concerned about the metadata changing underneath them.
> 
> Note that the message formatting functions can handle unexpected
> text buffer changes. So it is perfectly OK if a shared text buffer
> is clobbered by an interrupting context. The atomic console
> implementation will recognize the interruption and avoid printing
> the (probably garbage) text buffer.

Great description!

> Signed-off-by: John Ogness <john.ogness@linutronix.de>

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

Best Regards,
Petr

^ permalink raw reply	[flat|nested] 22+ messages in thread

* Re: [PATCH printk v4 6/8] printk: introduce console_prepend_dropped() for dropped messages
  2023-01-05 10:37 ` [PATCH printk v4 6/8] printk: introduce console_prepend_dropped() for dropped messages John Ogness
@ 2023-01-05 16:17   ` Petr Mladek
  2023-01-05 16:35     ` John Ogness
  0 siblings, 1 reply; 22+ messages in thread
From: Petr Mladek @ 2023-01-05 16:17 UTC (permalink / raw)
  To: John Ogness
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner, linux-kernel

On Thu 2023-01-05 11:43:33, John Ogness wrote:
> Currently "dropped messages" are separately printed immediately
> before printing the printk message. Since normal consoles are
> now using an output buffer that is much larger than previously,
> the "dropped message" could be prepended to the printk message
> and then output everything in a single write() call.
> 
> Introduce a helper function console_prepend_dropped() to prepend
> an existing message with a "dropped message". This simplifies
> the code by allowing all message formatting to be handled
> together and then only requires a single write() call to output
> the full message. And since this helper does not require any
> locking, it can be used in the future for other console printing
> contexts as well.
> 
> Signed-off-by: John Ogness <john.ogness@linutronix.de>

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

A comment below.

> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -2724,6 +2699,52 @@ static void __console_unlock(void)
>  	up_console_sem();
>  }
>  
> +/*
> + * Prepend the message in @pmsg->pbufs->outbuf with a "dropped message". This
> + * is achieved by shifting the existing message over and inserting the dropped
> + * message.
> + *
> + * @pmsg is the printk message to prepend.
> + *
> + * @dropped is the dropped count to report in the dropped message.
> + *
> + * If the message text in @pmsg->pbufs->outbuf does not have enough space for
> + * the dropped message, the message text will be sufficiently truncated.
> + *
> + * If @pmsg->pbufs->outbuf is modified, @pmsg->outbuf_len is updated.
> + */
> +static void console_prepend_dropped(struct printk_message *pmsg, unsigned long dropped)
> +{
> +	struct printk_buffers *pbufs = pmsg->pbufs;
> +	const size_t scratchbuf_sz = sizeof(pbufs->scratchbuf);
> +	const size_t outbuf_sz = sizeof(pbufs->outbuf);
> +	char *scratchbuf = &pbufs->scratchbuf[0];
> +	char *outbuf = &pbufs->outbuf[0];
> +	size_t len;
> +
> +	len = snprintf(scratchbuf, scratchbuf_sz,
> +		       "** %lu printk messages dropped **\n", dropped);
> +
> +	/*
> +	 * Make sure outbuf is sufficiently large before prepending.
> +	 * Keep at least the prefix when the message must be truncated.
> +	 * It is a rather theoretical problem when someone tries to
> +	 * use a minimalist buffer.
> +	 */
> +	if (WARN_ON_ONCE(len + PREFIX_MAX >= outbuf_sz))
> +		return;

I guess that this will always trigger the compiler warning
when CONFIG_PRINTK is disabled. See the report for v3 at
https://lore.kernel.org/r/202301052114.vvN3wQoH-lkp@intel.com

Hmm, we might want to fix this warning so that it does not break
build with -Werror.

IMHO, the proper solution would be to define this function only when
CONFIG_PRINTK is defined. But it might require bigger changes
and define many more console functions only when CONFIG_PRINTK
is defined. This is out-of-scope of this patchset.

I wonder if the following would work as an "intermediate" workaround:

	if (!IS_ENABLED(CONFIG_PRINTK) ||
	    WARN_ON_ONCE(len + PREFIX_MAX >= outbuf_sz))
		return;


Best Regards,
Petr

^ permalink raw reply	[flat|nested] 22+ messages in thread

* Re: [PATCH printk v4 6/8] printk: introduce console_prepend_dropped() for dropped messages
  2023-01-05 16:17   ` Petr Mladek
@ 2023-01-05 16:35     ` John Ogness
  2023-01-06  9:34       ` Petr Mladek
  0 siblings, 1 reply; 22+ messages in thread
From: John Ogness @ 2023-01-05 16:35 UTC (permalink / raw)
  To: Petr Mladek
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner, linux-kernel

On 2023-01-05, Petr Mladek <pmladek@suse.com> wrote:
>> +	if (WARN_ON_ONCE(len + PREFIX_MAX >= outbuf_sz))
>> +		return;
>
> I guess that this will always trigger the compiler warning
> when CONFIG_PRINTK is disabled. See the report for v3 at
> https://lore.kernel.org/r/202301052114.vvN3wQoH-lkp@intel.com

That report is actually complaining about the check after this one. It
is the same "problem".

> Hmm, we might want to fix this warning so that it does not break
> build with -Werror.
>
> IMHO, the proper solution would be to define this function only when
> CONFIG_PRINTK is defined. But it might require bigger changes
> and define many more console functions only when CONFIG_PRINTK
> is defined. This is out-of-scope of this patchset.
>
> I wonder if the following would work as an "intermediate" workaround:
>
> 	if (!IS_ENABLED(CONFIG_PRINTK) ||
> 	    WARN_ON_ONCE(len + PREFIX_MAX >= outbuf_sz))
> 		return;

The whole CONFIG_PRINTK stuff is a total mess right now. We should
definitely get that cleaned up at some point. As an intermediate
workaround, it might make more sense to just put the whole function
inside an "#ifdef CONFIG_PRINTK". It doesn't return anything anyway.

#ifdef CONFIG_PRINTK
static void console_prepend_dropped(struct printk_message *pmsg, unsigned long dropped)
{
...
}
#else
#define console_prepend_dropped(pmsg, dropped)
#endif

There are already places in the code that look like this (for example,
print_caller()).

Otherwise, if you want to use IS_ENABLED(), you will need it for both
checks.

John

^ permalink raw reply	[flat|nested] 22+ messages in thread

* Re: [PATCH printk v4 6/8] printk: introduce console_prepend_dropped() for dropped messages
  2023-01-05 16:35     ` John Ogness
@ 2023-01-06  9:34       ` Petr Mladek
  0 siblings, 0 replies; 22+ messages in thread
From: Petr Mladek @ 2023-01-06  9:34 UTC (permalink / raw)
  To: John Ogness
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner, linux-kernel

On Thu 2023-01-05 17:41:59, John Ogness wrote:
> On 2023-01-05, Petr Mladek <pmladek@suse.com> wrote:
> >> +	if (WARN_ON_ONCE(len + PREFIX_MAX >= outbuf_sz))
> >> +		return;
> >
> > I guess that this will always trigger the compiler warning
> > when CONFIG_PRINTK is disabled. See the report for v3 at
> > https://lore.kernel.org/r/202301052114.vvN3wQoH-lkp@intel.com
> 
> That report is actually complaining about the check after this one. It
> is the same "problem".

I see.

> > Hmm, we might want to fix this warning so that it does not break
> > build with -Werror.
> >
> > IMHO, the proper solution would be to define this function only when
> > CONFIG_PRINTK is defined. But it might require bigger changes
> > and define many more console functions only when CONFIG_PRINTK
> > is defined. This is out-of-scope of this patchset.
> >
> > I wonder if the following would work as an "intermediate" workaround:
> >
> > 	if (!IS_ENABLED(CONFIG_PRINTK) ||
> > 	    WARN_ON_ONCE(len + PREFIX_MAX >= outbuf_sz))
> > 		return;
> 
> The whole CONFIG_PRINTK stuff is a total mess right now. We should
> definitely get that cleaned up at some point. As an intermediate
> workaround, it might make more sense to just put the whole function
> inside an "#ifdef CONFIG_PRINTK". It doesn't return anything anyway.
> 
> #ifdef CONFIG_PRINTK
> static void console_prepend_dropped(struct printk_message *pmsg, unsigned long dropped)
> {
> ...
> }
> #else
> #define console_prepend_dropped(pmsg, dropped)
> #endif

Looks good.

The question is if we want to do it in this patch or as a follow up
fix.

I slightly prefer to do it as a follow up fix to avoid another respin.
Also we will not need to complicate this patch with explaining
why this is needed.

Best Regards,
Petr

^ permalink raw reply	[flat|nested] 22+ messages in thread

* Re: [PATCH printk v4 7/8 v2] printk: use printk_buffers for devkmsg
  2023-01-05 12:16     ` [PATCH printk v4 7/8 v2] " John Ogness
@ 2023-01-06 10:39       ` Petr Mladek
  2023-01-08 21:11         ` John Ogness
  0 siblings, 1 reply; 22+ messages in thread
From: Petr Mladek @ 2023-01-06 10:39 UTC (permalink / raw)
  To: John Ogness
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner, linux-kernel

On Thu 2023-01-05 13:22:16, John Ogness wrote:
> Replace the buffers in struct devkmsg_user with a struct
> printk_buffers. This reduces the number of buffers to track.
> 
> As a side-effect, @text_buf was 8kB large, even though it only
> needed to be the max size of a ringbuffer record. By switching to
> struct printk_buffers, ~7kB less memory is allocated when opening
> /dev/kmsg.
> 
> And since struct printk_buffers will be used now, reduce duplicate
> code by calling printk_get_next_message() to handle the record
> reading and formatting.

> Signed-off-by: John Ogness <john.ogness@linutronix.de>
> ---
>  kernel/printk/printk.c | 40 ++++++++++++++++------------------------
>  1 file changed, 16 insertions(+), 24 deletions(-)
> 
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 4fb7d29fb05d..32996b0c5d03 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -695,16 +695,14 @@ static ssize_t msg_print_ext_body(char *buf, size_t size,
>  	return len;
>  }
>  
> +static bool printk_get_next_message(struct printk_message *pmsg, u64 seq, bool is_extended);
> +
>  /* /dev/kmsg - userspace message inject/listen interface */
>  struct devkmsg_user {
>  	atomic64_t seq;
>  	struct ratelimit_state rs;
>  	struct mutex lock;
> -	char buf[CONSOLE_EXT_LOG_MAX];
> -
> -	struct printk_info info;
> -	char text_buf[CONSOLE_EXT_LOG_MAX];
> -	struct printk_record record;
> +	struct printk_buffers pbufs;
>  };
>  
>  static __printf(3, 4) __cold
> @@ -786,8 +784,10 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
>  			    size_t count, loff_t *ppos)
>  {
>  	struct devkmsg_user *user = file->private_data;
> -	struct printk_record *r = &user->record;
> -	size_t len;
> +	char *outbuf = &user->pbufs.outbuf[0];
> +	struct printk_message pmsg = {
> +		.pbufs = &user->pbufs,
> +	};
>  	ssize_t ret;
>  
>  	if (!user)
> @@ -797,7 +797,7 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
>  	if (ret)
>  		return ret;
>  
> -	if (!prb_read_valid(prb, atomic64_read(&user->seq), r)) {
> +	while (!printk_get_next_message(&pmsg, atomic64_read(&user->seq), true)) {

A problem is that printk_get_next_message() does not format the
message when it shoud get supressed on the console.

I would solve it be adding a parameter to printk_get_next_message() that
will tell whether to suppress or not, e.g. @can_suppress.

>  		if (file->f_flags & O_NONBLOCK) {
>  			ret = -EAGAIN;
>  			goto out;
> @@ -814,36 +814,31 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
>  		 * This pairs with __wake_up_klogd:A.
>  		 */
>  		ret = wait_event_interruptible(log_wait,
> -				prb_read_valid(prb,
> -					atomic64_read(&user->seq), r)); /* LMM(devkmsg_read:A) */
> +					       prb_read_valid(prb, atomic64_read(&user->seq),
> +							      NULL)); /* LMM(devkmsg_read:A) */

The above change from "if" to "while" could be avoided if we use
printk_get_next_message() here as well. It looks slightly more
strightfoward to me. Or do I miss something, please?


>  		if (ret)
>  			goto out;
>  	}
>  

Otherwise, I like this change. It simplifies the code.

Best Regards,
Petr

^ permalink raw reply	[flat|nested] 22+ messages in thread

* Re: [PATCH printk v4 8/8] printk: adjust string limit macros
  2023-01-05 10:37 ` [PATCH printk v4 8/8] printk: adjust string limit macros John Ogness
@ 2023-01-06 11:11   ` Petr Mladek
  0 siblings, 0 replies; 22+ messages in thread
From: Petr Mladek @ 2023-01-06 11:11 UTC (permalink / raw)
  To: John Ogness
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner, linux-kernel

On Thu 2023-01-05 11:43:35, John Ogness wrote:
> The various internal size limit macros have names and/or values that
> do not fit well to their current usage.
> 
> Rename the macros so that their purpose is clear and, if needed,
> provide a more appropriate value. In general, the new macros and
> values will lead to less memory usage. The new macros are...
> 
> PRINTK_MESSAGE_MAX:
> 
> This is the maximum size for a formatted message on a console,
> devkmsg, or syslog. It does not matter which format the message has
> (normal or extended). It replaces the use of CONSOLE_EXT_LOG_MAX for
> console and devkmsg. It replaces the use of CONSOLE_LOG_MAX for
> syslog.
> 
> Historically, normal messages have been allowed to print up to 1kB,
> whereas extended messages have been allowed to print up to 8kB.
> However, the difference in lengths of these message types is not
> significant and in multi-line records, normal messages are probably
> larger. Also, because 1kB is only slightly above the allowed record
> size, multi-line normal messages could be easily truncated during
> formatting.
> 
> This new macro should be significantly larger than the allowed
> record size to allow sufficient space for extended or multi-line
> prefix text. A value of 2kB should be plenty of space. For normal
> messages this represents a doubling of the historically allowed
> amount. For extended messages it reduces the excessive 8kB size,
> thus reducing memory usage needed for message formatting.
> 
> PRINTK_PREFIX_MAX:
> 
> This is the maximum size allowed for a record prefix (used by
> console and syslog). It replaces PREFIX_MAX. The value is left
> unchanged.
> 
> PRINTKRB_RECORD_MAX:
> 
> This is the maximum size allowed to be reserved for a record in the
> ringbuffer. It is used by all readers and writers with the printk
> ringbuffer. It replaces LOG_LINE_MAX.
> 
> Previously this was set to "1kB - PREFIX_MAX", which makes some
> sense if 1kB is the limit for normal message output and prefixes are
> enabled. However, with the allowance of larger output and the
> existence of multi-line records, the value is rather bizarre.
> 
> Round the value up to 1kB.
> 
> Signed-off-by: John Ogness <john.ogness@linutronix.de>

I like this.

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

Best Regards,
Petr

^ permalink raw reply	[flat|nested] 22+ messages in thread

* Re: [PATCH printk v4 0/8] printk: cleanup buffer handling
  2023-01-05 10:37 [PATCH printk v4 0/8] printk: cleanup buffer handling John Ogness
                   ` (7 preceding siblings ...)
  2023-01-05 10:37 ` [PATCH printk v4 8/8] printk: adjust string limit macros John Ogness
@ 2023-01-06 11:21 ` Petr Mladek
  2023-01-07  8:18   ` John Ogness
  8 siblings, 1 reply; 22+ messages in thread
From: Petr Mladek @ 2023-01-06 11:21 UTC (permalink / raw)
  To: John Ogness
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner,
	linux-kernel, Greg Kroah-Hartman

On Thu 2023-01-05 11:43:27, John Ogness wrote:
> Hi,
> 
> This is v4 of a series to cleanup console buffer handling and
> prepare for code sharing with the upcoming threaded/atomic
> consoles. v3 is here [0].
> 
> The main purpose of the series is to introduce two new lockless
> functions to handle reading and formatting of printk messages. These
> functions can then be used from any context, which is important for
> the upcoming threaded/atomic consoles. The series also helps to
> cleanup some of the internal printk interfaces and cleanly separate
> formatting code from outputting code.
> 
> John Ogness (6):
>   printk: move size limit macros into internal.h
>   printk: introduce struct printk_buffers
>   printk: introduce printk_get_next_message() and printk_message
>   printk: introduce console_prepend_dropped() for dropped messages

This patch would need a followup fix to prevent the compiler warning.

>   printk: use printk_buffers for devkmsg

This one would need respin to fix the problem with suppressed messages.

>   printk: adjust string limit macros
> 
> Thomas Gleixner (2):
>   console: Use BIT() macros for @flags values
>   console: Document struct console

The rest looks ready for linux-next.

I see three ways how to move forward:

1. Respin the entire patchset.
2. Respin only 7th patch + send the follow up fix seperately
3. Push first 6 patches and handle the rest separately.

What would be more convenient for you, please?
Honestly, I do not have any real preference.

Best Regards,
Petr

^ permalink raw reply	[flat|nested] 22+ messages in thread

* Re: [PATCH printk v4 0/8] printk: cleanup buffer handling
  2023-01-06 11:21 ` [PATCH printk v4 0/8] printk: cleanup buffer handling Petr Mladek
@ 2023-01-07  8:18   ` John Ogness
  0 siblings, 0 replies; 22+ messages in thread
From: John Ogness @ 2023-01-07  8:18 UTC (permalink / raw)
  To: Petr Mladek
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner,
	linux-kernel, Greg Kroah-Hartman

On 2023-01-06, Petr Mladek <pmladek@suse.com> wrote:
> On Thu 2023-01-05 11:43:27, John Ogness wrote:
> I see three ways how to move forward:
>
> 1. Respin the entire patchset.
> 2. Respin only 7th patch + send the follow up fix seperately
> 3. Push first 6 patches and handle the rest separately.

I will respin the entire patchset. That is easist for me and makes
things quite straight forward for you.

I still am looking into and will to respond to your comments on patch
7/8 before I do the respin.

John

^ permalink raw reply	[flat|nested] 22+ messages in thread

* Re: [PATCH printk v4 7/8 v2] printk: use printk_buffers for devkmsg
  2023-01-06 10:39       ` Petr Mladek
@ 2023-01-08 21:11         ` John Ogness
  0 siblings, 0 replies; 22+ messages in thread
From: John Ogness @ 2023-01-08 21:11 UTC (permalink / raw)
  To: Petr Mladek
  Cc: Sergey Senozhatsky, Steven Rostedt, Thomas Gleixner, linux-kernel

On 2023-01-06, Petr Mladek <pmladek@suse.com> wrote:
>> -	if (!prb_read_valid(prb, atomic64_read(&user->seq), r)) {
>> +	while (!printk_get_next_message(&pmsg, atomic64_read(&user->seq), true)) {
>
> A problem is that printk_get_next_message() does not format the
> message when it shoud get supressed on the console.

Nice catch. I missed that.

> I would solve it be adding a parameter to printk_get_next_message()
> that will tell whether to suppress or not, e.g. @can_suppress.

OK.

>>  		if (file->f_flags & O_NONBLOCK) {
>>  			ret = -EAGAIN;
>>  			goto out;
>> @@ -814,36 +814,31 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
>>  		 * This pairs with __wake_up_klogd:A.
>>  		 */
>>  		ret = wait_event_interruptible(log_wait,
>> -				prb_read_valid(prb,
>> -					atomic64_read(&user->seq), r)); /* LMM(devkmsg_read:A) */
>> +					       prb_read_valid(prb, atomic64_read(&user->seq),
>> +							      NULL)); /* LMM(devkmsg_read:A) */
>
> The above change from "if" to "while" could be avoided if we use
> printk_get_next_message() here as well. It looks slightly more
> strightfoward to me.

Yes, that is better. A loop is overkill here.

John

^ permalink raw reply	[flat|nested] 22+ messages in thread

end of thread, other threads:[~2023-01-08 21:12 UTC | newest]

Thread overview: 22+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2023-01-05 10:37 [PATCH printk v4 0/8] printk: cleanup buffer handling John Ogness
2023-01-05 10:37 ` [PATCH printk v4 1/8] printk: move size limit macros into internal.h John Ogness
2023-01-05 14:48   ` Petr Mladek
2023-01-05 10:37 ` [PATCH printk v4 2/8] console: Use BIT() macros for @flags values John Ogness
2023-01-05 10:37 ` [PATCH printk v4 3/8] console: Document struct console John Ogness
2023-01-05 10:37 ` [PATCH printk v4 4/8] printk: introduce struct printk_buffers John Ogness
2023-01-05 15:06   ` Petr Mladek
2023-01-05 10:37 ` [PATCH printk v4 5/8] printk: introduce printk_get_next_message() and printk_message John Ogness
2023-01-05 15:24   ` Petr Mladek
2023-01-05 10:37 ` [PATCH printk v4 6/8] printk: introduce console_prepend_dropped() for dropped messages John Ogness
2023-01-05 16:17   ` Petr Mladek
2023-01-05 16:35     ` John Ogness
2023-01-06  9:34       ` Petr Mladek
2023-01-05 10:37 ` [PATCH printk v4 7/8] printk: use printk_buffers for devkmsg John Ogness
2023-01-05 12:14   ` John Ogness
2023-01-05 12:16     ` [PATCH printk v4 7/8 v2] " John Ogness
2023-01-06 10:39       ` Petr Mladek
2023-01-08 21:11         ` John Ogness
2023-01-05 10:37 ` [PATCH printk v4 8/8] printk: adjust string limit macros John Ogness
2023-01-06 11:11   ` Petr Mladek
2023-01-06 11:21 ` [PATCH printk v4 0/8] printk: cleanup buffer handling Petr Mladek
2023-01-07  8:18   ` John Ogness

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.