[PATCH printk v2 0/7] printk: cleanup buffer handling

[PATCH printk v2 0/7] printk: cleanup buffer handling

[John Ogness]

Hi,

This is v2 of a series to cleanup buffer handling and prepare for
code sharing with the upcoming threaded/atomic consoles. v1 is
patches 13-18 of [0].

Changes since v1:

- Explain why console.h was chosen for buffer size defines.

- Keep DROPPED_TEXT_MAX define in printk.c.

- Put new BIT()-macro usage for console flags into its own commit.

- Modify descriptions for console flags as suggested.

- Add argument names and types to console callback definitions to
  satisfy checkpatch.pl complaints.

- Avoid temporary usage of an ext_text/dropped_text union mid-series.

- Rename various structures, fields, and functions:

    struct cons_text_buf    -> struct console_buffers

    struct cons_outbuf_desc -> struct console_message

    cons_outbuf_desc.txtbuf -> console_message.cbufs

    cons_outbuf_desc.len    -> console_message.outbuf_len

    cons_outbuf_desc.extmsg -> console_message.is_extmsg

    cons_fill_outbuf()      -> console_get_next_message()

    cons_print_dropped()    -> msg_print_dropped()

- Remove cons_outbuf_desc->dropped and make @dropped an argument of
  msg_print_dropped() instead.

- Use "ext_text" and "ext_text_size" names for stack variables when
  they refer to console_buffers->ext_text.

- Add a compile-time verification that DROPPED_TEXT_MAX is less than
  CONSOLE_EXT_LOG_MAX - CONSOLE_LOG_MAX since the code expects that
  a dropped+regular message will fit in console_buffers->ext_text.

- Replace hard-coded CONSOLE_LOG_MAX and CONSOLE_EXT_LOG_MAX usage
  with sizeof() usage.

- For dropped messages, copy the regular message to append the
  dropped message, instead of copying the dropped message to prepend
  the regular message. Now it is not a hack and there is no need for
  the __no_randomize_layout annotation.

- Reset console->dropped explicitly instead of relying on
  msg_print_dropped() side-effects.

- Rework and expand comments and commit messages as requested.

John Ogness

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

Thomas Gleixner (7):
  printk: Move buffer size defines
  console: Use BIT() macros for @flags values
  console: Document struct console
  printk: Add struct console_buffers
  printk: Use struct console_buffers
  printk: Use an output buffer descriptor struct for emit
  printk: Handle dropped message smarter

 include/linux/console.h | 139 ++++++++++++++++++-----
 include/linux/printk.h  |   2 -
 kernel/printk/printk.c  | 240 ++++++++++++++++++++++++++--------------
 3 files changed, 269 insertions(+), 112 deletions(-)


base-commit: 11f1e536902b38bffab9913f8908309daf7e53e1
-- 
2.30.2

[PATCH printk v2 1/7] printk: Move buffer size defines

[John Ogness]

From: Thomas Gleixner <tglx@linutronix.de>

Move the buffer size defines to console.h in preparation of adding a
buffer structure. The new buffer structure will be embedded within
struct console. Therefore console.h was chosen as the new home for
these defines.

Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
 include/linux/console.h | 14 ++++++++++++++
 include/linux/printk.h  |  2 --
 kernel/printk/printk.c  |  4 ----
 3 files changed, 14 insertions(+), 6 deletions(-)

diff --git a/include/linux/console.h b/include/linux/console.h
index 9cea254b34b8..799fc3216aad 100644
--- a/include/linux/console.h
+++ b/include/linux/console.h
@@ -122,6 +122,20 @@ static inline int con_debug_leave(void)
 #define CM_ERASE    (2)
 #define CM_MOVE     (3)
 
+#ifdef CONFIG_PRINTK
+
+/* The maximum size of a formatted record (i.e. with prefix added per line) */
+#define CONSOLE_LOG_MAX		1024
+
+#else
+
+#define CONSOLE_LOG_MAX		0
+
+#endif
+
+/* The maximum size of a formatted extended record */
+#define CONSOLE_EXT_LOG_MAX	8192
+
 /*
  * The interface for a console, or any other device that wants to capture
  * console messages (printer driver?)
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/printk.c b/kernel/printk/printk.c
index 9ec101766471..a4854a60e6d8 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -471,9 +471,6 @@ static struct latched_seq clear_seq = {
 #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
 
@@ -2387,7 +2384,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
 
-- 
2.30.2

[PATCH printk v2 2/7] console: Use BIT() macros for @flags values

[John Ogness]

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>
---
 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 799fc3216aad..f7a14ea6bae0 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>
 
@@ -139,18 +140,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

[PATCH printk v2 3/7] console: Document struct console

[John Ogness]

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>
---
 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 f7a14ea6bae0..b2cf256c23b6 100644
--- a/include/linux/console.h
+++ b/include/linux/console.h
@@ -178,24 +178,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 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

[PATCH printk v2 4/7] printk: Add struct console_buffers

[John Ogness]

From: Thomas Gleixner <tglx@linutronix.de>

Create a data structure to replace the open coded separate buffers for
regular, extended, and dropped message formatting.

A separate @ext_text buffer is needed because info_print_ext_header()
and msg_print_ext_body() are not able to add the needed extra
information in-place.

@ext_text can be used for dropped text because they are never used at
the same time.

Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
 include/linux/console.h | 10 ++++++++++
 1 file changed, 10 insertions(+)

diff --git a/include/linux/console.h b/include/linux/console.h
index b2cf256c23b6..641c1ca7fb67 100644
--- a/include/linux/console.h
+++ b/include/linux/console.h
@@ -178,6 +178,16 @@ enum cons_flags {
 	CON_EXTENDED		= BIT(6),
 };
 
+/**
+ * struct console_buffers - console output text buffers
+ * @ext_text:		Buffer for extended log format or dropped text
+ * @text:		Buffer for ringbuffer text
+ */
+struct console_buffers {
+	char	ext_text[CONSOLE_EXT_LOG_MAX];
+	char	text[CONSOLE_LOG_MAX];
+};
+
 /**
  * struct console - The console descriptor structure
  * @name:		The name of the console driver
-- 
2.30.2

[PATCH printk v2 5/7] printk: Use struct console_buffers

[John Ogness]

From: Thomas Gleixner <tglx@linutronix.de>

Replace the separately allocated output buffers with a single
instance of struct console_buffers.

Note that the buffer size of devkmsg_user.text_buf, when replaced
with console_buffers.text, reduces from CONSOLE_EXT_LOG_MAX to
CONSOLE_LOG_MAX. However, the buffer is only used to read ringbuffer
records. These records have a maximum size of LOG_LINE_MAX, which
is defined as CONSOLE_LOG_MAX - PREFIX_MAX.

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

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index a4854a60e6d8..750559171e30 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -712,11 +712,9 @@ 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 console_buffers cbufs;
 };
 
 static __printf(3, 4) __cold
@@ -798,6 +796,8 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
 			    size_t count, loff_t *ppos)
 {
 	struct devkmsg_user *user = file->private_data;
+	const int ext_text_size = sizeof(user->cbufs.ext_text);
+	char *ext_text = &user->cbufs.ext_text[0];
 	struct printk_record *r = &user->record;
 	size_t len;
 	ssize_t ret;
@@ -839,8 +839,8 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
 		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,
+	len = info_print_ext_header(ext_text, ext_text_size, r->info);
+	len += msg_print_ext_body(ext_text + len, ext_text_size - len,
 				  &r->text_buf[0], r->info->text_len,
 				  &r->info->dev_info);
 
@@ -851,7 +851,7 @@ static ssize_t devkmsg_read(struct file *file, char __user *buf,
 		goto out;
 	}
 
-	if (copy_to_user(buf, user->buf, len)) {
+	if (copy_to_user(buf, ext_text, len)) {
 		ret = -EFAULT;
 		goto out;
 	}
@@ -950,7 +950,7 @@ 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));
+			&user->cbufs.text[0], sizeof(user->cbufs.text));
 
 	atomic64_set(&user->seq, prb_first_valid_seq(prb));
 
@@ -2007,6 +2007,10 @@ static int console_trylock_spinning(void)
 	return 1;
 }
 
+#if DROPPED_TEXT_MAX > CONSOLE_EXT_LOG_MAX
+#error "DROPPED_TEXT_MAX too large for console_buffers->ext_text"
+#endif
+
 /*
  * 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
@@ -2741,36 +2745,32 @@ 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.
+ * @cbufs is the console buffers used to string-print the formatted messages.
  *
- * 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.
+ * @cookie is the cookie from entering the SRCU read-side critical section.
  *
  * @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, char *text, char *ext_text,
-				     char *dropped_text, bool *handover, int cookie)
+static bool console_emit_next_record(struct console *con, struct console_buffers *cbufs,
+				     int cookie, bool *handover)
 {
 	static int panic_console_dropped;
 	struct printk_info info;
 	struct printk_record r;
+	size_t write_text_size;
 	unsigned long flags;
+	char *dropped_text;
 	char *write_text;
 	size_t len;
 
-	prb_rec_init_rd(&r, &info, text, CONSOLE_LOG_MAX);
+	prb_rec_init_rd(&r, &info, &cbufs->text[0], sizeof(cbufs->text));
 
 	*handover = false;
 
@@ -2792,13 +2792,20 @@ 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 (console_srcu_read_flags(con) & CON_EXTENDED) {
+		/* Extended consoles do not print "dropped messages". */
+		dropped_text = NULL;
+
+		write_text = &cbufs->ext_text[0];
+		write_text_size = sizeof(cbufs->ext_text);
+		len = info_print_ext_header(write_text, write_text_size, r.info);
+		len += msg_print_ext_body(write_text + len, write_text_size - len,
 					  &r.text_buf[0], r.info->text_len, &r.info->dev_info);
 	} else {
-		write_text = text;
+		/* @ext_text is unused. Use it for "dropped messages". */
+		dropped_text = &cbufs->ext_text[0];
+
+		write_text = &cbufs->text[0];
 		len = record_print_text(&r, console_msg_format & MSG_FORMAT_SYSLOG, printk_time);
 	}
 
@@ -2852,9 +2859,7 @@ 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];
+	static struct console_buffers cbufs;
 	bool any_usable = false;
 	struct console *con;
 	bool any_progress;
@@ -2874,16 +2879,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, &cbufs, cookie, handover);
 
 			/*
 			 * If a handover has occurred, the SRCU read lock
-- 
2.30.2

[PATCH printk v2 6/7] printk: Use an output buffer descriptor struct for emit

[John Ogness]

From: Thomas Gleixner <tglx@linutronix.de>

To prepare for a new console infrastructure that is independent of
the console BKL, wrap the output mode into a descriptor struct so
the new infrastructure can share the emit code that dumps the
ringbuffer record into the output text buffers.

Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
 include/linux/console.h |  15 ++++++
 kernel/printk/printk.c  | 107 ++++++++++++++++++++++++++++------------
 2 files changed, 90 insertions(+), 32 deletions(-)

diff --git a/include/linux/console.h b/include/linux/console.h
index 641c1ca7fb67..32614011a950 100644
--- a/include/linux/console.h
+++ b/include/linux/console.h
@@ -188,6 +188,21 @@ struct console_buffers {
 	char	text[CONSOLE_LOG_MAX];
 };
 
+/**
+ * struct console_message - console output buffer descriptor
+ * @cbufs:		Pointer to console buffers storing the record text
+ * @outbuf:		Pointer to the text buffer to be used for writing out
+ *			to the device
+ * @outbuf_len:		Length of text at @outbuf
+ * @is_extmsg:		True if this is an extended format message
+ */
+struct console_message {
+	struct console_buffers	*cbufs;
+	char			*outbuf;
+	unsigned int		outbuf_len;
+	bool			is_extmsg;
+};
+
 /**
  * struct console - The console descriptor structure
  * @name:		The name of the console driver
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 750559171e30..dd1d8599ce5a 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2741,11 +2741,76 @@ static void __console_unlock(void)
 	up_console_sem();
 }
 
+/**
+ * console_get_next_message - Fill the output buffer with the next record
+ * @con:	The console to print on
+ * @cmsg:	Pointer to the output buffer descriptor
+ *
+ * Return: False if there is no pending record in the ringbuffer.
+ *	   True if there is a pending record in the ringbuffer.
+ *
+ * When the return value is true, then the caller must check
+ * @cmsg->outbuf. If not NULL it points to the first character to write
+ * to the device and @cmsg->outbuf_len contains the length of the message.
+ * If it is NULL then the record will be skipped.
+ */
+static bool console_get_next_message(struct console *con, struct console_message *cmsg)
+{
+	struct console_buffers *cbufs = cmsg->cbufs;
+	static int panic_console_dropped;
+	struct printk_info info;
+	struct printk_record r;
+	size_t write_text_size;
+	char *write_text;
+	size_t len;
+
+	cmsg->outbuf = NULL;
+	cmsg->outbuf_len = 0;
+
+	prb_rec_init_rd(&r, &info, &cbufs->text[0], sizeof(cbufs->text));
+
+	if (!prb_read_valid(prb, con->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");
+		}
+	}
+
+	/*
+	 * Skip record that has level above the console loglevel.
+	 * Return true so the caller knows a record exists and
+	 * leave cmsg->outbuf NULL so the caller knows the record
+	 * is being skipped.
+	 */
+	if (suppress_message_printing(r.info->level))
+		return true;
+
+	if (cmsg->is_extmsg) {
+		write_text = &cbufs->ext_text[0];
+		write_text_size = sizeof(cbufs->ext_text);
+		len = info_print_ext_header(write_text, write_text_size, r.info);
+		len += msg_print_ext_body(write_text + len, write_text_size - len,
+					  &r.text_buf[0], r.info->text_len, &r.info->dev_info);
+	} else {
+		write_text = &cbufs->text[0];
+		len = record_print_text(&r, console_msg_format & MSG_FORMAT_SYSLOG, printk_time);
+	}
+
+	cmsg->outbuf = write_text;
+	cmsg->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.
  *
- * @cbufs is the console buffers used to string-print the formatted messages.
+ * @cbufs is the console buffers to use for string-printing the message.
  *
  * @cookie is the cookie from entering the SRCU read-side critical section.
  *
@@ -2761,52 +2826,30 @@ static void __console_unlock(void)
 static bool console_emit_next_record(struct console *con, struct console_buffers *cbufs,
 				     int cookie, bool *handover)
 {
-	static int panic_console_dropped;
-	struct printk_info info;
-	struct printk_record r;
-	size_t write_text_size;
+	struct console_message cmsg = {
+		.cbufs		= cbufs,
+		.is_extmsg	= console_srcu_read_flags(con) & CON_EXTENDED,
+	};
 	unsigned long flags;
 	char *dropped_text;
-	char *write_text;
-	size_t len;
-
-	prb_rec_init_rd(&r, &info, &cbufs->text[0], sizeof(cbufs->text));
 
 	*handover = false;
 
-	if (!prb_read_valid(prb, con->seq, &r))
+	if (!console_get_next_message(con, &cmsg))
 		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");
-		}
-	}
-
-	/* Skip record that has level above the console loglevel. */
-	if (suppress_message_printing(r.info->level)) {
+	if (!cmsg.outbuf) {
+		/* Skipping this record. */
 		con->seq++;
 		goto skip;
 	}
 
-	if (console_srcu_read_flags(con) & CON_EXTENDED) {
+	if (cmsg.is_extmsg) {
 		/* Extended consoles do not print "dropped messages". */
 		dropped_text = NULL;
-
-		write_text = &cbufs->ext_text[0];
-		write_text_size = sizeof(cbufs->ext_text);
-		len = info_print_ext_header(write_text, write_text_size, r.info);
-		len += msg_print_ext_body(write_text + len, write_text_size - len,
-					  &r.text_buf[0], r.info->text_len, &r.info->dev_info);
 	} else {
 		/* @ext_text is unused. Use it for "dropped messages". */
 		dropped_text = &cbufs->ext_text[0];
-
-		write_text = &cbufs->text[0];
-		len = record_print_text(&r, console_msg_format & MSG_FORMAT_SYSLOG, printk_time);
 	}
 
 	/*
@@ -2823,7 +2866,7 @@ static bool console_emit_next_record(struct console *con, struct console_buffers
 	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, cmsg.outbuf, cmsg.outbuf_len, dropped_text);
 	start_critical_timings();
 
 	con->seq++;
-- 
2.30.2

[PATCH printk v2 7/7] printk: Handle dropped message smarter

[John Ogness]

From: Thomas Gleixner <tglx@linutronix.de>

If a 'dropped message' is to be printed, move the record text to be
directly appended to the 'dropped message' and let console->write()
output it in one go.

Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
 kernel/printk/printk.c | 125 +++++++++++++++++++++++++++--------------
 1 file changed, 82 insertions(+), 43 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index dd1d8599ce5a..c4b148a7d114 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2007,31 +2007,6 @@ static int console_trylock_spinning(void)
 	return 1;
 }
 
-#if DROPPED_TEXT_MAX > CONSOLE_EXT_LOG_MAX
-#error "DROPPED_TEXT_MAX too large for console_buffers->ext_text"
-#endif
-
-/*
- * 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
@@ -2412,10 +2387,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; }
@@ -2741,6 +2712,60 @@ static void __console_unlock(void)
 	up_console_sem();
 }
 
+/*
+ * A maximum dropped message together with a maximum regular message
+ * must be able to fit within console_buffers->ext_text.
+ */
+#if DROPPED_TEXT_MAX > (CONSOLE_EXT_LOG_MAX - CONSOLE_LOG_MAX)
+#error "DROPPED_TEXT_MAX too large for console_buffers->ext_text"
+#endif
+
+/**
+ * msg_print_dropped - Prepend a "dropped message" if required
+ * @desc:	Pointer to the output descriptor
+ * @dropped:	The number of dropped messages to report
+ *
+ * Inserts the "dropped message" into the output buffer if @dropped is
+ * not 0 and the regular format is requested. Extended format does not
+ * need this message because it prints the sequence numbers.
+ *
+ * In regular format, the extended message buffer is not in use. So
+ * string-print the dropped message there and move the record text to be
+ * appended to the dropped message. The extended message buffer is much
+ * larger and can accommodate both messages.
+ *
+ * In case a dropped message is needed, this returns with @desc->outbuf
+ * and @desc->len updated. The caller is responsible for tracking and
+ * resetting the dropped count. If no dropped message is required then
+ * @desc is not modified.
+ */
+static void msg_print_dropped(struct console_message *cmsg, unsigned long dropped)
+{
+	struct console_buffers *cbufs = cmsg->cbufs;
+	char *ext_text = &cbufs->ext_text[0];
+	size_t len;
+
+	if (!dropped || cmsg->is_extmsg)
+		return;
+
+	if (WARN_ON_ONCE(cmsg->outbuf != &cbufs->text[0]))
+		return;
+
+	/* Print it into ext_text, which is unused. */
+	len = snprintf(ext_text, DROPPED_TEXT_MAX,
+		       "** %lu printk messages dropped **\n", dropped);
+
+	/*
+	 * Append the record text to the dropped message so that it
+	 * goes out with one write.
+	 */
+	memcpy(ext_text + len, &cbufs->text[0], cmsg->outbuf_len);
+
+	/* Update the output buffer descriptor. */
+	cmsg->outbuf = ext_text;
+	cmsg->outbuf_len += len;
+}
+
 /**
  * console_get_next_message - Fill the output buffer with the next record
  * @con:	The console to print on
@@ -2796,13 +2821,32 @@ static bool console_get_next_message(struct console *con, struct console_message
 		len = info_print_ext_header(write_text, write_text_size, r.info);
 		len += msg_print_ext_body(write_text + len, write_text_size - len,
 					  &r.text_buf[0], r.info->text_len, &r.info->dev_info);
+
+		cmsg->outbuf = write_text;
+		cmsg->outbuf_len = len;
+
+		/*
+		 * Extended consoles do not print "dropped messages"
+		 * as that can be seen from the sequence number.
+		 */
 	} else {
-		write_text = &cbufs->text[0];
 		len = record_print_text(&r, console_msg_format & MSG_FORMAT_SYSLOG, printk_time);
+
+		cmsg->outbuf = &cbufs->text[0];
+		cmsg->outbuf_len = len;
+
+		if (con->dropped) {
+			/*
+			 * It is expected that @outbuf and @outbuf_len are
+			 * already set. They will be updated after inserting
+			 * the "dropped message".
+			 */
+			msg_print_dropped(cmsg, con->dropped);
+
+			con->dropped = 0;
+		}
 	}
 
-	cmsg->outbuf = write_text;
-	cmsg->outbuf_len = len;
 	return true;
 }
 
@@ -2831,7 +2875,6 @@ static bool console_emit_next_record(struct console *con, struct console_buffers
 		.is_extmsg	= console_srcu_read_flags(con) & CON_EXTENDED,
 	};
 	unsigned long flags;
-	char *dropped_text;
 
 	*handover = false;
 
@@ -2844,14 +2887,6 @@ static bool console_emit_next_record(struct console *con, struct console_buffers
 		goto skip;
 	}
 
-	if (cmsg.is_extmsg) {
-		/* Extended consoles do not print "dropped messages". */
-		dropped_text = NULL;
-	} else {
-		/* @ext_text is unused. Use it for "dropped messages". */
-		dropped_text = &cbufs->ext_text[0];
-	}
-
 	/*
 	 * While actively printing out messages, if another printk()
 	 * were to occur on another CPU, it may wait for this one to
@@ -2865,8 +2900,12 @@ static bool console_emit_next_record(struct console *con, struct console_buffers
 	printk_safe_enter_irqsave(flags);
 	console_lock_spinning_enable();
 
-	stop_critical_timings();	/* don't trace print latency */
-	call_console_driver(con, cmsg.outbuf, cmsg.outbuf_len, dropped_text);
+	/* Do not trace print latency. */
+	stop_critical_timings();
+
+	/* Write everything out to the hardware. */
+	con->write(con, cmsg.outbuf, cmsg.outbuf_len);
+
 	start_critical_timings();
 
 	con->seq++;
-- 
2.30.2

Re: [PATCH printk v2 1/7] printk: Move buffer size defines

[Petr Mladek]

On Thu 2022-11-24 00:19:54, John Ogness wrote:
> From: Thomas Gleixner <tglx@linutronix.de>
> 
> Move the buffer size defines to console.h in preparation of adding a
> buffer structure. The new buffer structure will be embedded within
> struct console. Therefore console.h was chosen as the new home for
> these defines.

The buffers are not embedded into struct console in this patchset.
Are they going to be added directly or via pointer, please?

IMHO, it is always better to hide these implementation details
in an internal header or source file. It will be possible
if struct console contained on a pointer to the buffers.


> Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
> Signed-off-by: John Ogness <john.ogness@linutronix.de>
> ---
>  include/linux/console.h | 14 ++++++++++++++
>  include/linux/printk.h  |  2 --
>  kernel/printk/printk.c  |  4 ----
>  3 files changed, 14 insertions(+), 6 deletions(-)
> 
> diff --git a/include/linux/console.h b/include/linux/console.h
> index 9cea254b34b8..799fc3216aad 100644
> --- a/include/linux/console.h
> +++ b/include/linux/console.h
> @@ -122,6 +122,20 @@ static inline int con_debug_leave(void)
>  #define CM_ERASE    (2)
>  #define CM_MOVE     (3)
>  
> +#ifdef CONFIG_PRINTK
> +
> +/* The maximum size of a formatted record (i.e. with prefix added per line) */
> +#define CONSOLE_LOG_MAX		1024
> +
> +#else
> +
> +#define CONSOLE_LOG_MAX		0
> +
> +#endif
> +
> +/* The maximum size of a formatted extended record */
> +#define CONSOLE_EXT_LOG_MAX	8192

It looks strange that we need the buffer for extended messages
and not the normal one when !CONFIG_PRINTK. I can't find any reason
for this. It looks like a historic inconsistency.

CONSOLE_EXT_LOG_MAX was added into printk.h in the commit
d43ff430f434d862db59 ("printk: guard the amount written per line
by devkmsg_read()"). It didn't have to be in include/linux/printk.h
at that time. But nobody cared, including me, I was a greenhorn ;-)

Well, it would be nice to fix it when we are moving the definition
next to each other.

Best Regards,
Petr

Re: [PATCH printk v2 2/7] console: Use BIT() macros for @flags values

[Petr Mladek]

On Thu 2022-11-24 00:19:55, John Ogness wrote:
> 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>

This is really useful.

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

Best Regards,
Petr

Re: [PATCH printk v2 1/7] printk: Move buffer size defines

[John Ogness]

On 2022-11-24, Petr Mladek <pmladek@suse.com> wrote:
>> Move the buffer size defines to console.h in preparation of adding a
>> buffer structure. The new buffer structure will be embedded within
>> struct console. Therefore console.h was chosen as the new home for
>> these defines.
>
> The buffers are not embedded into struct console in this patchset.
> Are they going to be added directly or via pointer, please?

By "embedded" I mean added directly. The buffers need to be available
immediately and cannot be allocated or assigned dynamically. The console
struct is generally defined by drivers with:

static struct console my_console = {
   ...
};

I could think of no way to statically define the buffers but keep their
sizes hidden.

> IMHO, it is always better to hide these implementation details
> in an internal header or source file. It will be possible
> if struct console contained on a pointer to the buffers.

The problem is not pointers, it is static definition (without knowing
the size of the thing that is statically defined). The new thread/atomic
consoles run in parallel, so they cannot share the single static buffer
like we do now.

>> --- a/include/linux/console.h
>> +++ b/include/linux/console.h
>> @@ -122,6 +122,20 @@ static inline int con_debug_leave(void)
>>  #define CM_ERASE    (2)
>>  #define CM_MOVE     (3)
>>  
>> +#ifdef CONFIG_PRINTK
>> +
>> +/* The maximum size of a formatted record (i.e. with prefix added per line) */
>> +#define CONSOLE_LOG_MAX		1024
>> +
>> +#else
>> +
>> +#define CONSOLE_LOG_MAX		0
>> +
>> +#endif
>> +
>> +/* The maximum size of a formatted extended record */
>> +#define CONSOLE_EXT_LOG_MAX	8192
>
> It looks strange that we need the buffer for extended messages
> and not the normal one when !CONFIG_PRINTK. I can't find any reason
> for this. It looks like a historic inconsistency.

Yes, it looked that way to me as well. I will move it under
CONFIG_PRINTK for v3.

John

Re: [PATCH printk v2 3/7] console: Document struct console

[Petr Mladek]

On Thu 2022-11-24 00:19:56, John Ogness wrote:
> 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>

Nice improvement.

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

Best Regards,
Petr

Re: [PATCH printk v2 1/7] printk: Move buffer size defines

[Petr Mladek]

On Thu 2022-11-24 13:44:29, John Ogness wrote:
> On 2022-11-24, Petr Mladek <pmladek@suse.com> wrote:
> >> Move the buffer size defines to console.h in preparation of adding a
> >> buffer structure. The new buffer structure will be embedded within
> >> struct console. Therefore console.h was chosen as the new home for
> >> these defines.
> >
> > The buffers are not embedded into struct console in this patchset.
> > Are they going to be added directly or via pointer, please?
> 
> By "embedded" I mean added directly. The buffers need to be available
> immediately and cannot be allocated or assigned dynamically. The console
> struct is generally defined by drivers with:
> 
> static struct console my_console = {
>    ...
> };
> 
> I could think of no way to statically define the buffers but keep their
> sizes hidden.
> 
> > IMHO, it is always better to hide these implementation details
> > in an internal header or source file. It will be possible
> > if struct console contained on a pointer to the buffers.
> 
> The problem is not pointers, it is static definition (without knowing
> the size of the thing that is statically defined). The new thread/atomic
> consoles run in parallel, so they cannot share the single static buffer
> like we do now.

Let me to play a devil advocate first:

Well, allocation is possible long before scheduling is
possible. It is actually available even before early parameters
are proceed where the boot consoles are registered. At least
it is used when setup_log_buf(1) is called in setup_arch() on x86.

The motivation is that only thread/atomic consoles would need
the console-specific buffer. The other consoles might share
the global one.

It would be useful even for atomic consoles. IMHO, most users
use generic kernels that support a variety of hardware. They
would provide static buffers for many console drivers but
only one or two would be used in the end.

Also the atomic consoles would need these buffers for each context.
It might be even more useful to allocate them dynamically.

Or do I miss something, please?


That said:

I do not have any numbers at hands to show how this
is important. Also I do not know if the early allocations
have some limits.

The static buffers might be acceptable for simplicity and
reliability after all.

Feel free to keep them static. I would ack the next version
of this patch after making the CONSOLE_EXT_LOG_MAX dependent
on CONFIG_PRINTK.

Best Regards,
Petr

Re: [PATCH printk v2 4/7] printk: Add struct console_buffers

[Petr Mladek]

On Thu 2022-11-24 00:19:57, John Ogness wrote:
> From: Thomas Gleixner <tglx@linutronix.de>
> 
> Create a data structure to replace the open coded separate buffers for
> regular, extended, and dropped message formatting.
> 
> A separate @ext_text buffer is needed because info_print_ext_header()
> and msg_print_ext_body() are not able to add the needed extra
> information in-place.
> 
> @ext_text can be used for dropped text because they are never used at
> the same time.
> 
> Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
> Signed-off-by: John Ogness <john.ogness@linutronix.de>

If we agree to use the static buffers in struct console, feel free to use:

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

Otherwise, it should get moved into some internal header.

Best Regards,
Petr

Re: [PATCH printk v2 5/7] printk: Use struct console_buffers

[Petr Mladek]

On Thu 2022-11-24 00:19:58, John Ogness wrote:
> From: Thomas Gleixner <tglx@linutronix.de>
> 
> Replace the separately allocated output buffers with a single
> instance of struct console_buffers.
> 
> Note that the buffer size of devkmsg_user.text_buf, when replaced
> with console_buffers.text, reduces from CONSOLE_EXT_LOG_MAX to
> CONSOLE_LOG_MAX. However, the buffer is only used to read ringbuffer
> records. These records have a maximum size of LOG_LINE_MAX, which
> is defined as CONSOLE_LOG_MAX - PREFIX_MAX.
> 
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -2007,6 +2007,10 @@ static int console_trylock_spinning(void)
>  	return 1;
>  }
>  
> +#if DROPPED_TEXT_MAX > CONSOLE_EXT_LOG_MAX
> +#error "DROPPED_TEXT_MAX too large for console_buffers->ext_text"
> +#endif

A better solution would be to remove DROPPED_TEXT_MAX completely
and pass the buffer size to call_console_driver(). I mean to do:

static void call_console_driver(struct console *con, const char *text, size_t len,
-				char *dropped_text)
+				char *dropped_text, size_t dropped_text_size)
{
	size_t dropped_len;

-	if (con->dropped && dropped_text) {
-		dropped_len = snprintf(dropped_text, DROPPED_TEXT_MAX,
+	if (con->dropped && dropped_text && dropped_text_size) {
+		dropped_len = snprintf(dropped_text, dropped_text_size,
				       "** %lu printk messages dropped **\n",
				       con->dropped);
		con->dropped = 0;
		con->write(con, dropped_text, dropped_len);
	}

	con->write(con, text, len);
}

The rest looks good. And it is a nice clean up.

Best Regards,
Petr

Re: [PATCH printk v2 6/7] printk: Use an output buffer descriptor struct for emit

[Petr Mladek]

On Thu 2022-11-24 00:19:59, John Ogness wrote:
> From: Thomas Gleixner <tglx@linutronix.de>
> 
> To prepare for a new console infrastructure that is independent of
> the console BKL, wrap the output mode into a descriptor struct so
> the new infrastructure can share the emit code that dumps the
> ringbuffer record into the output text buffers.
> 
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -2741,11 +2741,76 @@ static void __console_unlock(void)
>  	up_console_sem();
>  }
>  
> +/**
> + * console_get_next_message - Fill the output buffer with the next record
> + * @con:	The console to print on
> + * @cmsg:	Pointer to the output buffer descriptor
> + *
> + * Return: False if there is no pending record in the ringbuffer.
> + *	   True if there is a pending record in the ringbuffer.
> + *
> + * When the return value is true, then the caller must check
> + * @cmsg->outbuf. If not NULL it points to the first character to write
> + * to the device and @cmsg->outbuf_len contains the length of the message.
> + * If it is NULL then the record will be skipped.
> + */
> +static bool console_get_next_message(struct console *con, struct console_message *cmsg)
> +{

I wish, this change was done in two patches. 1st introducing and
using struct console_message. 2nd moving the code into separate
console_get_next_message().

I do not resist on it but it might help to see what exactly has changed.

> +	struct console_buffers *cbufs = cmsg->cbufs;
> +	static int panic_console_dropped;
> +	struct printk_info info;
> +	struct printk_record r;
> +	size_t write_text_size;
> +	char *write_text;
> +	size_t len;
> +
> +	cmsg->outbuf = NULL;
> +	cmsg->outbuf_len = 0;
> +
> +	prb_rec_init_rd(&r, &info, &cbufs->text[0], sizeof(cbufs->text));
> +
> +	if (!prb_read_valid(prb, con->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");
> +		}
> +	}
> +
> +	/*
> +	 * Skip record that has level above the console loglevel.
> +	 * Return true so the caller knows a record exists and
> +	 * leave cmsg->outbuf NULL so the caller knows the record
> +	 * is being skipped.
> +	 */
> +	if (suppress_message_printing(r.info->level))
> +		return true;
> +
> +	if (cmsg->is_extmsg) {
> +		write_text = &cbufs->ext_text[0];
> +		write_text_size = sizeof(cbufs->ext_text);
> +		len = info_print_ext_header(write_text, write_text_size, r.info);
> +		len += msg_print_ext_body(write_text + len, write_text_size - len,
> +					  &r.text_buf[0], r.info->text_len, &r.info->dev_info);
> +	} else {
> +		write_text = &cbufs->text[0];
> +		len = record_print_text(&r, console_msg_format & MSG_FORMAT_SYSLOG, printk_time);
> +	}
> +
> +	cmsg->outbuf = write_text;
> +	cmsg->outbuf_len = len;

Please, remove "write_text" variable and use cmsg->outbuf directly.
It would safe one mental transition of buffer names:

   cbufs->text -> write_text -> cmsg->outbuf

vs.

   cbufs->text -> cmsg->outbuf

Best Regards,
Petr

PS: Please, wait a bit with updating the patches. I have got yet
    another idea when seeing the code around dropped messages.
    But I have to sleep over it.

    My concern is that the message about dropped messages need not
    fit into the smaller "cbufs->text" buffer. It might be better
    to put it into the bigger one.

    We might actually always use the bigger buffer as the output
    buffer. The smaller buffer might be only temporary when formatting
    the extended messages.

     We could replace

	struct console_buffers {
		char	ext_text[CONSOLE_EXT_LOG_MAX];
		char	text[CONSOLE_LOG_MAX];
	};

    with

	struct console_buffers {
		char	outbuf[CONSOLE_EXT_LOG_MAX];
		char	readbuf[CONSOLE_LOG_MAX];
	};

     Normal consoles would use only @outbuf. Only the extended console
     would need the @readbuf to read the messages before they are formatted.

     I guess that struct console_message won't be needed then at all.

     It might help to remove several twists in the code.

     I am sorry that I have not got this idea when reviewing v1.
     Well, the code was even more complicated at that time.

OFFLIST: Re: [PATCH printk v2 6/7] printk: Use an output buffer descriptor struct for emit

[Petr Mladek]

On Thu 2022-11-24 19:00:14, Petr Mladek wrote:
> PS: Please, wait a bit with updating the patches. I have got yet
>     another idea when seeing the code around dropped messages.
>     But I have to sleep over it.
> 
>     My concern is that the message about dropped messages need not
>     fit into the smaller "cbufs->text" buffer. It might be better
>     to put it into the bigger one.
> 
>     We might actually always use the bigger buffer as the output
>     buffer. The smaller buffer might be only temporary when formatting
>     the extended messages.
> 
>      We could replace
> 
> 	struct console_buffers {
> 		char	ext_text[CONSOLE_EXT_LOG_MAX];
> 		char	text[CONSOLE_LOG_MAX];
> 	};
> 
>     with
> 
> 	struct console_buffers {
> 		char	outbuf[CONSOLE_EXT_LOG_MAX];
> 		char	readbuf[CONSOLE_LOG_MAX];
> 	};
> 
>      Normal consoles would use only @outbuf. Only the extended console
>      would need the @readbuf to read the messages before they are formatted.
> 
>      I guess that struct console_message won't be needed then at all.
> 
>      It might help to remove several twists in the code.
> 
>      I am sorry that I have not got this idea when reviewing v1.
>      Well, the code was even more complicated at that time.

Honestly, I haven't looked if you extended struct console_messages in
later patches that added the atomic consoles. It is possible that
the structure will be needed in the end anyway.

This was just an idea. You know, I always try to simplify things.
And many layers, pointers to the same buffers with different names,
makes things complicated.

Well, there are always many ways how to design the code and I do not
want to delay it too much with trying them all. Please, tell me
when you think that some changes are not worth the effort.

Best Regards,
Petr

Re: [PATCH printk v2 1/7] printk: Move buffer size defines

[John Ogness]

On 2022-11-24, Petr Mladek <pmladek@suse.com> wrote:
> The motivation is that only thread/atomic consoles would need
> the console-specific buffer. The other consoles might share
> the global one.

I understand what you are saying. I will change it to a pointer and
assign it to an internal shared global static buffer on
register_console(). Then we can keep the size defines private.

For the upcoming thread/atomic consoles, I will setup the sprint-buffers
differently.

> Also the atomic consoles would need these buffers for each context.
> It might be even more useful to allocate them dynamically.

Yes, atomic consoles need dedicated per-console, per-cpu, per-context
buffers. Some of these are allocated dynamically. I will revisit this
with the idea of minimizing static buffers.

John

Re: [PATCH printk v2 4/7] printk: Add struct console_buffers

[John Ogness]

On 2022-11-24, Petr Mladek <pmladek@suse.com> wrote:
> If we agree to use the static buffers in struct console, feel free to use:
>
> Reviewed-by: Petr Mladek <pmladek@suse.com>

I will move the struct definition and size defines into printk.c for v3.

John

Re: [PATCH printk v2 5/7] printk: Use struct console_buffers

[John Ogness]

On 2022-11-24, Petr Mladek <pmladek@suse.com> wrote:
> A better solution would be to remove DROPPED_TEXT_MAX completely
> and pass the buffer size to call_console_driver().

And then call:

    call_cosole_driver(con, text, len, dropped_text, DROPPED_TEXT_MAX);

Is that better? We do not want to pass the actual buffer size because
the buffer is shared with the regular messages.

Later in this series the dropped messages are handled in quite a
different way, so maybe this mid-series solution is acceptable. But even
by the end of this series DROPPED_TEXT_MAX still exists just to put a
limit on the dropped messages length, even if more buffer space exists.

John

Re: [PATCH printk v2 6/7] printk: Use an output buffer descriptor struct for emit

[John Ogness]

On 2022-11-24, Petr Mladek <pmladek@suse.com> wrote:
> I wish, this change was done in two patches. 1st introducing and
> using struct console_message. 2nd moving the code into separate
> console_get_next_message().

OK.

>> +	if (cmsg->is_extmsg) {
>> +		write_text = &cbufs->ext_text[0];
>> +		write_text_size = sizeof(cbufs->ext_text);
>> +		len = info_print_ext_header(write_text, write_text_size, r.info);
>> +		len += msg_print_ext_body(write_text + len, write_text_size - len,
>> +					  &r.text_buf[0], r.info->text_len, &r.info->dev_info);
>> +	} else {
>> +		write_text = &cbufs->text[0];
>> +		len = record_print_text(&r, console_msg_format & MSG_FORMAT_SYSLOG, printk_time);
>> +	}
>> +
>> +	cmsg->outbuf = write_text;
>> +	cmsg->outbuf_len = len;
>
> Please, remove "write_text" variable and use cmsg->outbuf directly.
> It would safe one mental transition of buffer names:
>
>    cbufs->text -> write_text -> cmsg->outbuf
>
> vs.
>
>    cbufs->text -> cmsg->outbuf

I originally had the non-extended case without @write_text. I felt like
it was harder to follow what actually got set. Really the main objective
of the function is to set @outbuf and @outbuf_len. I felt like moving
that outside of the if/else block made it clearer what is going on. But
I can go back to having each if/else branch set those fields in their
own way.

> PS: Please, wait a bit with updating the patches. I have got yet
>     another idea when seeing the code around dropped messages.
>     But I have to sleep over it.

Don't worry. I always wait until you finish the full review before
touching anything. ;-)

>     My concern is that the message about dropped messages need not
>     fit into the smaller "cbufs->text" buffer. It might be better
>     to put it into the bigger one.

This series _does_ put the dropped messages in the bigger one.

>     We might actually always use the bigger buffer as the output
>     buffer. The smaller buffer might be only temporary when formatting
>     the extended messages.
>
>      We could replace
>
> 	struct console_buffers {
> 		char	ext_text[CONSOLE_EXT_LOG_MAX];
> 		char	text[CONSOLE_LOG_MAX];
> 	};
>
>     with
>
> 	struct console_buffers {
> 		char	outbuf[CONSOLE_EXT_LOG_MAX];
> 		char	readbuf[CONSOLE_LOG_MAX];
> 	};
>
>      Normal consoles would use only @outbuf. Only the extended console
>      would need the @readbuf to read the messages before they are
>      formatted.

The "problem" with this idea is that record_print_text() creates the
normal output in-place within the readbuf. So for normal messages with
no dropped messages, we still end up writing out the readbuf.

>      I guess that struct console_message won't be needed then at all.

Since we sometimes output the in-place readbuf and sometimes a newly
written buffer, it is nice that console_message can abstract that out.

Also, right now @is_extmsg is the only input variable. For thread/atomic
consoles, the input variables @seq and @dropped will be added.
console_message will then have its own copy of all the information
needed to let itself get filled and console_get_next_message() will no
longer require the console as an argument.

This is important for the thread/atomic consoles because it removes all
locking constraints from console_get_next_message(). For _this_ series,
console_get_next_message() still requires holding the console_lock
because it is accessing con->seq and con->dropped.

I could have added @seq and @dropped to console_message for this series,
but for the legacy consoles it looks like a lot of unnecessary
copying. Only with the thread/atomic consoles does the benefit become
obvious.

>      It might help to remove several twists in the code.

A lot of this is preparation for the thread/atomic consoles. It is a
little bit twisty because it is primarily designed for the new
consoles. The trick is to get us from old to new without things getting
crazy in between.

I appreciate your comments. You see things from the perspective of the
"legacy consoles", which is helpful for us to keep things clean and
maintainable during the transition.

John

Re: [PATCH printk v2 6/7] printk: Use an output buffer descriptor struct for emit

[Petr Mladek]

On Thu 2022-11-24 22:21:08, John Ogness wrote:
> On 2022-11-24, Petr Mladek <pmladek@suse.com> wrote:
> > I wish, this change was done in two patches. 1st introducing and
> > using struct console_message. 2nd moving the code into separate
> > console_get_next_message().
> 
> OK.
> 
> >> +	if (cmsg->is_extmsg) {
> >> +		write_text = &cbufs->ext_text[0];
> >> +		write_text_size = sizeof(cbufs->ext_text);
> >> +		len = info_print_ext_header(write_text, write_text_size, r.info);
> >> +		len += msg_print_ext_body(write_text + len, write_text_size - len,
> >> +					  &r.text_buf[0], r.info->text_len, &r.info->dev_info);
> >> +	} else {
> >> +		write_text = &cbufs->text[0];
> >> +		len = record_print_text(&r, console_msg_format & MSG_FORMAT_SYSLOG, printk_time);
> >> +	}
> >> +
> >> +	cmsg->outbuf = write_text;
> >> +	cmsg->outbuf_len = len;
> >
> > Please, remove "write_text" variable and use cmsg->outbuf directly.
> > It would safe one mental transition of buffer names:
> >
> >    cbufs->text -> write_text -> cmsg->outbuf
> >
> > vs.
> >
> >    cbufs->text -> cmsg->outbuf
> 
> I originally had the non-extended case without @write_text. I felt like
> it was harder to follow what actually got set. Really the main objective
> of the function is to set @outbuf and @outbuf_len. I felt like moving
> that outside of the if/else block made it clearer what is going on. But
> I can go back to having each if/else branch set those fields in their
> own way.

I am not sure if we are talking about the same thing. My idea was to do:

	if (cmsg->is_extmsg) {
		cmsg->outbuf = &cbufs->ext_text[0];
		outbuf_size = sizeof(cbufs->ext_text);
		len = info_print_ext_header(cmsg->outbuf, outbuf_size, r.info);
		len += msg_print_ext_body(cmsg->outbuf + len, outbuf_size - len,
				  &r.text_buf[0], r.info->text_len, &r.info->dev_info);
	} else {
		cmsg->outbuf = &cbufs->text[0];
		/* &r points to &cbufs->text[0], changes are done inline */
		len = record_print_text(&r, console_msg_format & MSG_FORMAT_SYSLOG, printk_time);
	}

> > PS: Please, wait a bit with updating the patches. I have got yet
> >     another idea when seeing the code around dropped messages.
> >     But I have to sleep over it.
> 
> Don't worry. I always wait until you finish the full review before
> touching anything. ;-)
> 
> >     My concern is that the message about dropped messages need not
> >     fit into the smaller "cbufs->text" buffer. It might be better
> >     to put it into the bigger one.
> 
> This series _does_ put the dropped messages in the bigger one.

Ah, I have overlooked this. It might actually be a motivation to avoid
all these shuffles and really use:

	struct console_buffers {
		char	outbuf[CONSOLE_EXT_LOG_MAX];
		char	readbuf[CONSOLE_LOG_MAX];
	};
> >
> >      Normal consoles would use only @outbuf. Only the extended console
> >      would need the @readbuf to read the messages before they are
> >      formatted.
> 
> The "problem" with this idea is that record_print_text() creates the
> normal output in-place within the readbuf. So for normal messages with
> no dropped messages, we still end up writing out the readbuf.

We handle this this in console_get_next_message() by reading the
messages into the right buffer:

	boot is_extcon = console_srcu_read_flags(con) & CON_EXTENDED;

	/*
	 * Normal consoles might read the message into the outbuf directly.
	 * Console headers are added inplace.
	 */
	if (is_extcon)
		prb_rec_init_rd(&r, &info, &cbufs->readbuf[0], sizeof(cbufs->readbuf));
	else
		prb_rec_init_rd(&r, &info, &cbufs->outbuf[0], sizeof(cbufs->outbuf));

	if (!prb_read_valid(prb, con->seq, &r))
		return false;

	...


	if (is_extcon) {
		len = info_print_ext_header(cbufs->outbuf, sizeof(cbufs->outbuf, r.info);
		len += msg_print_ext_body(cbufs->outbuf + len, sizeof(cbufs->outbuf) - len,
				  &r.text_buf[0], r.info->text_len, &r.info->dev_info);
	} else {
		len = record_print_text(&r, console_msg_format & MSG_FORMAT_SYSLOG, printk_time);
	}



> >      I guess that struct console_message won't be needed then at all.
> 
> Since we sometimes output the in-place readbuf and sometimes a newly
> written buffer, it is nice that console_message can abstract that out.
> 
> Also, right now @is_extmsg is the only input variable. For thread/atomic
> consoles, the input variables @seq and @dropped will be added.
> console_message will then have its own copy of all the information
> needed to let itself get filled and console_get_next_message() will no
> longer require the console as an argument.
> 
> This is important for the thread/atomic consoles because it removes all
> locking constraints from console_get_next_message(). For _this_ series,
> console_get_next_message() still requires holding the console_lock
> because it is accessing con->seq and con->dropped.
> 
> I could have added @seq and @dropped to console_message for this series,
> but for the legacy consoles it looks like a lot of unnecessary
> copying. Only with the thread/atomic consoles does the benefit become
> obvious.

I could imagine adding these metadata into the struct console_buffers.
Or we could call it struct console_messages from the beginning.

We could even completely move con->seq, con->dropped into this new
structure. It would safe even more copies.

IMHO, the less structures and the less copying the better.
Especially when the values have different name in each structure
that makes it even more complicated.

Best Regards,
Petr

Re: [PATCH printk v2 6/7] printk: Use an output buffer descriptor struct for emit

[John Ogness]

On 2022-11-25, Petr Mladek <pmladek@suse.com> wrote:
> I am not sure if we are talking about the same thing. My idea was to
> do:

We are and your idea is fine.

>> The "problem" with this idea is that record_print_text() creates the
>> normal output in-place within the readbuf. So for normal messages with
>> no dropped messages, we still end up writing out the readbuf.
>
> We handle this this in console_get_next_message() by reading the
> messages into the right buffer:
>
> 	struct console_buffers {
> 		char	outbuf[CONSOLE_EXT_LOG_MAX];
> 		char	readbuf[CONSOLE_LOG_MAX];
> 	};
>
> 	boot is_extcon = console_srcu_read_flags(con) & CON_EXTENDED;
>
> 	/*
> 	 * Normal consoles might read the message into the outbuf directly.
> 	 * Console headers are added inplace.
> 	 */
> 	if (is_extcon)
> 		prb_rec_init_rd(&r, &info, &cbufs->readbuf[0], sizeof(cbufs->readbuf));
> 	else
> 		prb_rec_init_rd(&r, &info, &cbufs->outbuf[0], sizeof(cbufs->outbuf));
>
> 	if (!prb_read_valid(prb, con->seq, &r))
> 		return false;

We do not know if there will be dropped messages until _after_ we call
prb_read_valid().

> 	if (is_extcon) {
> 		len = info_print_ext_header(cbufs->outbuf, sizeof(cbufs->outbuf, r.info);
> 		len += msg_print_ext_body(cbufs->outbuf + len, sizeof(cbufs->outbuf) - len,
> 				  &r.text_buf[0], r.info->text_len, &r.info->dev_info);
> 	} else {
> 		len = record_print_text(&r, console_msg_format & MSG_FORMAT_SYSLOG, printk_time);
> 	}

And the dropped messages should be inserted now somewhere too.

The fact is that we need two different sized buffers. Which one is used
for output is not known in advance. I think it is misleading to name the
variables based on their purpose because their purpose changes depending
on the situation.

I think the only usefulness we can derive from the names is their
size. How about naming them:

@buffer_console_log_max
@buffer_console_ext_log_max

>> Since we sometimes output the in-place readbuf and sometimes a newly
>> written buffer, it is nice that console_message can abstract that
>> out.
>> 
>> Also, right now @is_extmsg is the only input variable. For
>> thread/atomic consoles, the input variables @seq and @dropped will be
>> added.  console_message will then have its own copy of all the
>> information needed to let itself get filled and
>> console_get_next_message() will no longer require the console as an
>> argument.
>> 
>> This is important for the thread/atomic consoles because it removes
>> all locking constraints from console_get_next_message(). For _this_
>> series, console_get_next_message() still requires holding the
>> console_lock because it is accessing con->seq and con->dropped.
>> 
>> I could have added @seq and @dropped to console_message for this
>> series, but for the legacy consoles it looks like a lot of
>> unnecessary copying. Only with the thread/atomic consoles does the
>> benefit become obvious.
>
> I could imagine adding these metadata into the struct console_buffers.
> Or we could call it struct console_messages from the beginning.
>
> We could even completely move con->seq, con->dropped into this new
> structure. It would safe even more copies.

Well, consoles still need to have their own copy of @seq and @dropped
for proper per-console tracking. But the buffers are globally shared.

For this series I will drop @is_extmsg from struct console_message and
instead make it an argument of console_get_next_message() and
msg_print_dropped(). That makes more sense at this point. (It needs to
be a variable because it is not safe to re-read flags multiple times
when constructing the message.)

For v3 I will move the two buffers (with whatever name we decide is
best) into struct console_message and remove the struct console_buffers
definition. That will also remove the use of @cbufs everywhere.

For devkmsg I can replace @cbufs with separate @readbuf and @outbuf
buffers since that is always their correct purpose for devkmsg.

John

Re: [PATCH printk v2 6/7] printk: Use an output buffer descriptor struct for emit

[Petr Mladek]

On Fri 2022-11-25 11:55:28, John Ogness wrote:
> On 2022-11-25, Petr Mladek <pmladek@suse.com> wrote:
> >> The "problem" with this idea is that record_print_text() creates the
> >> normal output in-place within the readbuf. So for normal messages with
> >> no dropped messages, we still end up writing out the readbuf.
> >
> > We handle this this in console_get_next_message() by reading the
> > messages into the right buffer:
> >
> > 	struct console_buffers {
> > 		char	outbuf[CONSOLE_EXT_LOG_MAX];
> > 		char	readbuf[CONSOLE_LOG_MAX];
> > 	};
> >
> > 	boot is_extcon = console_srcu_read_flags(con) & CON_EXTENDED;
> >
> > 	/*
> > 	 * Normal consoles might read the message into the outbuf directly.
> > 	 * Console headers are added inplace.
> > 	 */
> > 	if (is_extcon)
> > 		prb_rec_init_rd(&r, &info, &cbufs->readbuf[0], sizeof(cbufs->readbuf));
> > 	else
> > 		prb_rec_init_rd(&r, &info, &cbufs->outbuf[0], sizeof(cbufs->outbuf));
> >
> > 	if (!prb_read_valid(prb, con->seq, &r))
> > 		return false;
> 
> We do not know if there will be dropped messages until _after_ we call
> prb_read_valid().

Yes.

> > 	if (is_extcon) {
> > 		len = info_print_ext_header(cbufs->outbuf, sizeof(cbufs->outbuf, r.info);
> > 		len += msg_print_ext_body(cbufs->outbuf + len, sizeof(cbufs->outbuf) - len,
> > 				  &r.text_buf[0], r.info->text_len, &r.info->dev_info);
> > 	} else {
> > 		len = record_print_text(&r, console_msg_format & MSG_FORMAT_SYSLOG, printk_time);
> > 	}
> 
> And the dropped messages should be inserted now somewhere too.
> 
> The fact is that we need two different sized buffers. Which one is used
> for output is not known in advance. I think it is misleading to name the
> variables based on their purpose because their purpose changes depending
> on the situation.

I still think that changing the purpose of the buffers complicates
the code[*] and is potential source of problems. It might be even
a sign of a bad design. IMHO, it would be a big win if the buffers
have a better defined meaning.

The message about dropped messages is rather short. What about
using a small buffer on stack. And adding it into outbuf
by shuffling the existing message. It is not that complicated.
IMHO, it would be worth it.

> > I could imagine adding these metadata into the struct console_buffers.
> > Or we could call it struct console_messages from the beginning.
> >
> > We could even completely move con->seq, con->dropped into this new
> > structure. It would safe even more copies.
> 
> Well, consoles still need to have their own copy of @seq and @dropped
> for proper per-console tracking. But the buffers are globally shared.

Right. I have missed this. OK, what about the following?

struct console_buffers {
	char	outbuf[CONSOLE_EXT_LOG_MAX];
	char	readbuf[CONSOLE_LOG_MAX];
};

struct console_message {
	struct console_buffers *bufs;
	u64 seq;
	unsigned long dropped;
	unsigned int len;  ???
};

struct console {
[...]
	struct console_message *msg;
[...]
};

It will cause that the buffers will be on the 3rd level of
nesting. But I think that we would use the following everywhere
anyway:

void console_func(struct console *con)
{
	char *outbuf = con->bufs->outbuf;

	do_something(outbuf);
}

We could actually even use in console_get_next_message():

	/*
	 * Normal console headers are added inplace. Extended console
	 * headers need to read the messages into a separate buffer.
	 */
	if (is_extcon) {
		readbuf = con->bufs->readbuf;
		redbuf_size = sizeof(con->bufs->readbuf);
	} else {
		readbuf = con->bufs->outbuf;
		redbuf_size = sizeof(con->bufs->outbuf);
	}

IMHO, this should be the only function where this "hack"
would be needed. All others would work just with outbuf.

IMHO, one big advantage is using the same names everywhere.
Another advantage is that it won't be necessary to copy
the values between different structures.

> For this series I will drop @is_extmsg from struct console_message and
> instead make it an argument of console_get_next_message() and
> msg_print_dropped(). That makes more sense at this point. (It needs to
> be a variable because it is not safe to re-read flags multiple times
> when constructing the message.)
> 
> For v3 I will move the two buffers (with whatever name we decide is
> best) into struct console_message and remove the struct console_buffers
> definition. That will also remove the use of @cbufs everywhere.

This looks like a bad idea after all. I forgot that we wanted to share
the buffers between non-atomic consoles. It would be ugly to share
also the metadata, like @seq.

That said, I do not want to get stuck on this. If you still
do not like my proposal feel free to keep the text/text_ext
buffers and struct console_message abstraction. I think that
I could live with it.

Best Regards,
Petr

Re: [PATCH printk v2 7/7] printk: Handle dropped message smarter

[Petr Mladek]

On Thu 2022-11-24 00:20:00, John Ogness wrote:
> From: Thomas Gleixner <tglx@linutronix.de>
> 
> If a 'dropped message' is to be printed, move the record text to be
> directly appended to the 'dropped message' and let console->write()
> output it in one go.
>
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -2741,6 +2712,60 @@ static void __console_unlock(void)
>  	up_console_sem();
>  }
>  
> +/*
> + * A maximum dropped message together with a maximum regular message
> + * must be able to fit within console_buffers->ext_text.
> + */
> +#if DROPPED_TEXT_MAX > (CONSOLE_EXT_LOG_MAX - CONSOLE_LOG_MAX)
> +#error "DROPPED_TEXT_MAX too large for console_buffers->ext_text"
> +#endif
> +
> +/**
> + * msg_print_dropped - Prepend a "dropped message" if required
> + * @desc:	Pointer to the output descriptor
> + * @dropped:	The number of dropped messages to report
> + *
> + * Inserts the "dropped message" into the output buffer if @dropped is
> + * not 0 and the regular format is requested. Extended format does not
> + * need this message because it prints the sequence numbers.
> + *
> + * In regular format, the extended message buffer is not in use. So
> + * string-print the dropped message there and move the record text to be
> + * appended to the dropped message. The extended message buffer is much
> + * larger and can accommodate both messages.
> + *
> + * In case a dropped message is needed, this returns with @desc->outbuf
> + * and @desc->len updated. The caller is responsible for tracking and
> + * resetting the dropped count. If no dropped message is required then
> + * @desc is not modified.
> + */
> +static void msg_print_dropped(struct console_message *cmsg, unsigned long dropped)
> +{
> +	struct console_buffers *cbufs = cmsg->cbufs;
> +	char *ext_text = &cbufs->ext_text[0];
> +	size_t len;
> +
> +	if (!dropped || cmsg->is_extmsg)
> +		return;
> +
> +	if (WARN_ON_ONCE(cmsg->outbuf != &cbufs->text[0]))
> +		return;
> +
> +	/* Print it into ext_text, which is unused. */
> +	len = snprintf(ext_text, DROPPED_TEXT_MAX,
> +		       "** %lu printk messages dropped **\n", dropped);
> +

I would feel better if we check here that the text fits into the rest
of the buffer.

	if (WARN_ON_ONCE(len + cmsg->outbuf_len < sizeof(cbufs->ext_text)))
		return;

I know that it is kind-of guaranteed by the above compilation check
of the *_MAX values. But there might be a bug and cmsg->outbuf_len
might contains a garbage.


> +	/*
> +	 * Append the record text to the dropped message so that it
> +	 * goes out with one write.
> +	 */
> +	memcpy(ext_text + len, &cbufs->text[0], cmsg->outbuf_len);
> +
> +	/* Update the output buffer descriptor. */
> +	cmsg->outbuf = ext_text;
> +	cmsg->outbuf_len += len;

I still think that it would be better to rename the buffers in
struct console_message and avoid the switches of the purpose
of the two buffers.

We could print the message about dropped text into a local buffer
on stack. IMHO, 64 bytes are acceptable. And we could insert it
into the outbuf by shuffling the existing text. Something like:

static void msg_print_dropped(struct console_message *cmsg,
			      unsinged long dropped)
{
	char dropped_msg[DROPPED_TEXT_MAX];
	int dropped_len;

	if (!con->dropped)
		return 0;

	/* Print it into ext_text, which is unused. */
	dropped_len = snprintf(dropped_msg, sizeof(dropped_msg),
		       "** %lu printk messages dropped **\n", con->dropped);

	/*
	 * The buffer might already be full only where the message consist
	 * of many very short lines. It is not much realistic.
	 */
	if (cmsg->outbuf_len + dropped_len + 1 > sizeof(cmsg->outbuf)) {
		/* Should never happen. */
		if (WARN_ON_ONCE(dropped_len + 1 > sizeof(cmsg->outbuf)))
			return;

		/* Trunk the message like in record_print_text() */
		cmsg->outbuf_len = sizeof(cmsg->outbuf) - dropped_len;
		cmsg->outbuf[cmsg->outbuf_len] = '\0';
	}

	memmove(cmsg->outbuf + dropped_len, cmsg->outbuf, cmsg->outbuf_len + 1);
	memcpy(cmsg->outbuf, dropped_msg, dropped_len);
}

The handling of the full buffer is a bit ugly. I though about other
alternatives. For example, returning -ENOMEM, so that the caller
could print the line later. Or just using WARN_ON_ONCE() and return.

Any solution has its pros and cons. But is a corner case. It need
not be perfect. I solved it the same way as we already do in
record_print_text().

Otherwise, the move of the code makes sense.

Best Regards,
Petr

Re: [PATCH printk v2 7/7] printk: Handle dropped message smarter

[John Ogness]

On 2022-12-07, Petr Mladek <pmladek@suse.com> wrote:
>> +	/* Print it into ext_text, which is unused. */
>> +	len = snprintf(ext_text, DROPPED_TEXT_MAX,
>> +		       "** %lu printk messages dropped **\n", dropped);
>> +
>
> I would feel better if we check here that the text fits into the rest
> of the buffer.
>
> 	if (WARN_ON_ONCE(len + cmsg->outbuf_len < sizeof(cbufs->ext_text)))
> 		return;
>
> I know that it is kind-of guaranteed by the above compilation check
> of the *_MAX values. But there might be a bug and cmsg->outbuf_len
> might contains a garbage.

OK.

>> +	/*
>> +	 * Append the record text to the dropped message so that it
>> +	 * goes out with one write.
>> +	 */
>> +	memcpy(ext_text + len, &cbufs->text[0], cmsg->outbuf_len);
>> +
>> +	/* Update the output buffer descriptor. */
>> +	cmsg->outbuf = ext_text;
>> +	cmsg->outbuf_len += len;
>
> I still think that it would be better to rename the buffers in
> struct console_message and avoid the switches of the purpose
> of the two buffers.
>
> We could print the message about dropped text into a local buffer
> on stack. IMHO, 64 bytes are acceptable. And we could insert it
> into the outbuf by shuffling the existing text. Something like:
>
> static void msg_print_dropped(struct console_message *cmsg,
> 			      unsinged long dropped)
> {
> 	char dropped_msg[DROPPED_TEXT_MAX];
> 	int dropped_len;
>
> 	if (!con->dropped)
> 		return 0;
>
> 	/* Print it into ext_text, which is unused. */
> 	dropped_len = snprintf(dropped_msg, sizeof(dropped_msg),
> 		       "** %lu printk messages dropped **\n", con->dropped);
>
> 	/*
> 	 * The buffer might already be full only where the message consist
> 	 * of many very short lines. It is not much realistic.
> 	 */
> 	if (cmsg->outbuf_len + dropped_len + 1 > sizeof(cmsg->outbuf)) {
> 		/* Should never happen. */

This certainly can happen. @text is size CONSOLE_LOG_MAX, which is
LOG_LINE_MAX+PREFIX_MAX. So a totally legal formatted message of length
LOG_LINE_MAX-1 and a prefix will suddenly become truncated.

> 		if (WARN_ON_ONCE(dropped_len + 1 > sizeof(cmsg->outbuf)))
> 			return;
>
> 		/* Trunk the message like in record_print_text() */
> 		cmsg->outbuf_len = sizeof(cmsg->outbuf) - dropped_len;
> 		cmsg->outbuf[cmsg->outbuf_len] = '\0';
> 	}
>
> 	memmove(cmsg->outbuf + dropped_len, cmsg->outbuf, cmsg->outbuf_len + 1);
> 	memcpy(cmsg->outbuf, dropped_msg, dropped_len);
> }

I do not like the idea of increasing stack usage, possibly cutting off
messages, and performing extra memory operations all because of some
variable naming. There is literally a larger unused buffer just sitting
there.

I want struct console_buffers to be a black box of working buffers used
to process the different types of messages. console_get_next_message()
is the only function that should go inside that black box because it is
responsible for creating the actual message.

The caller does not care what is in the black box or how those internal
working buffers are named. The caller just cares about cmsg->outbuf and
cmsg->outbuf_len, which will point to the data that needs to be written
out.

For v3 I would like to try my approach one more time. I will give the
internal buffers new names so as not to mislead their roles. I will
clearly document the black box nature of struct console_buffers.

John Ogness

Re: [PATCH printk v2 7/7] printk: Handle dropped message smarter

[Petr Mladek]

On Wed 2022-12-07 18:04:56, John Ogness wrote:
> On 2022-12-07, Petr Mladek <pmladek@suse.com> wrote:
> >> +	/*
> >> +	 * Append the record text to the dropped message so that it
> >> +	 * goes out with one write.
> >> +	 */
> >> +	memcpy(ext_text + len, &cbufs->text[0], cmsg->outbuf_len);
> >> +
> >> +	/* Update the output buffer descriptor. */
> >> +	cmsg->outbuf = ext_text;
> >> +	cmsg->outbuf_len += len;
> >
> > I still think that it would be better to rename the buffers in
> > struct console_message and avoid the switches of the purpose
> > of the two buffers.
> >
> > We could print the message about dropped text into a local buffer
> > on stack. IMHO, 64 bytes are acceptable. And we could insert it
> > into the outbuf by shuffling the existing text. Something like:
> >
> > static void msg_print_dropped(struct console_message *cmsg,
> > 			      unsinged long dropped)
> > {
> > 	char dropped_msg[DROPPED_TEXT_MAX];
> > 	int dropped_len;
> >
> > 	if (!con->dropped)
> > 		return 0;
> >
> > 	/* Print it into ext_text, which is unused. */
> > 	dropped_len = snprintf(dropped_msg, sizeof(dropped_msg),
> > 		       "** %lu printk messages dropped **\n", con->dropped);
> >
> > 	/*
> > 	 * The buffer might already be full only where the message consist
> > 	 * of many very short lines. It is not much realistic.
> > 	 */
> > 	if (cmsg->outbuf_len + dropped_len + 1 > sizeof(cmsg->outbuf)) {
> > 		/* Should never happen. */
> 
> This certainly can happen. @text is size CONSOLE_LOG_MAX, which is
> LOG_LINE_MAX+PREFIX_MAX. So a totally legal formatted message of length
> LOG_LINE_MAX-1 and a prefix will suddenly become truncated.
> 
> > 		if (WARN_ON_ONCE(dropped_len + 1 > sizeof(cmsg->outbuf)))
> > 			return;
> >
> > 		/* Trunk the message like in record_print_text() */
> > 		cmsg->outbuf_len = sizeof(cmsg->outbuf) - dropped_len;
> > 		cmsg->outbuf[cmsg->outbuf_len] = '\0';
> > 	}
> >
> > 	memmove(cmsg->outbuf + dropped_len, cmsg->outbuf, cmsg->outbuf_len + 1);
> > 	memcpy(cmsg->outbuf, dropped_msg, dropped_len);
> > }
> 
> I do not like the idea of increasing stack usage, possibly cutting off
> messages, and performing extra memory operations all because of some
> variable naming. There is literally a larger unused buffer just sitting
> there.

Sigh. Your approach is copying buffers:

    DROPPED_LOG_MAX + CONSOLE_LOG_MAX -> CONSOLE_EXT_LOG_MAX

which means:

    64 + 1024 -> 8182

The important thing is that it will shrink the text in
record_print_text() to 1024.

With my approach, it would shrink the text here to 8182 - 64 = 8118.

> I want struct console_buffers to be a black box of working buffers used
> to process the different types of messages. console_get_next_message()
> is the only function that should go inside that black box because it is
> responsible for creating the actual message.
> 
> The caller does not care what is in the black box or how those internal
> working buffers are named. The caller just cares about cmsg->outbuf and
> cmsg->outbuf_len, which will point to the data that needs to be written
> out.
> 
> For v3 I would like to try my approach one more time. I will give the
> internal buffers new names so as not to mislead their roles. I will
> clearly document the black box nature of struct console_buffers.

This is probably my last mail on this matter[*]. I do not want to get
stuck here. But I really do not see any advantage in your approach:

    + The risk of shrinking the text is bigger.

    + The buffer is accessed via one more dereference that might
      eventually point to a wrong buffer if there is a bug.

    + The size of the buffer is not clear via the dereference
      and might be wrong if there is a bug.

    + The more layers, the more code complexity, like more names.


The only argument might be the 64B on stack. But it is nothing against
namebuf[KSYM_NAME_LEN] that is used in kallsyms code that might be
called via vsprintf.c. It is 512B on the stack. So I do not take it.

Another argument might be if you wanted to use the buffers yet another
way in the atomic consoles. But I guess (hope) that they will always
work only with the "outbuf".

[*] I think that I'll learn how to live with whatever you use in v3 :-)

Best Regards,
Petr