From: Thomas Gleixner <tglx@linutronix.de>

No need for an extra buffer type. Regular formatting which needs the '$N
messages dropped' printout can sprintf() it into the unused extended text
buffer.

As a further simplification move the 'dropped' message right in front of
the actual record text and let the write function output it in one go.

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

diff --git a/include/linux/console.h b/include/linux/console.h
index 590ab62c01d9..83563694cc82 100644
--- a/include/linux/console.h
+++ b/include/linux/console.h
@@ -176,28 +176,26 @@ enum cons_flags {
 /**
  * struct cons_text_buf - console output text buffer
  * @ext_text:		Buffer for extended log format text
- * @dropped_text:	Buffer for dropped text
  * @text:		Buffer for ringbuffer text
  */
 struct cons_text_buf {
-	union {
-		char	ext_text[CONSOLE_EXT_LOG_MAX];
-		char	dropped_text[DROPPED_TEXT_MAX];
-	};
-	char		text[CONSOLE_LOG_MAX];
-};
+	char	ext_text[CONSOLE_EXT_LOG_MAX];
+	char	text[CONSOLE_LOG_MAX];
+} __no_randomize_layout;
 
 /**
  * struct cons_outbuf_desc - console output buffer descriptor
  * @txtbuf:		Pointer to buffer for storing the text
  * @outbuf:		Pointer to the position in @buffer for
  *			writing it out to the device
+ * @dropped:		The dropped count
  * @len:		Message length
  * @extmsg:		Select extended format printing
  */
 struct cons_outbuf_desc {
 	struct cons_text_buf	*txtbuf;
 	char			*outbuf;
+	unsigned long		dropped;
 	unsigned int		len;
 	bool			extmsg;
 };
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index c9207d81b90c..14ddd5c9363f 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1961,27 +1961,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
@@ -2361,10 +2340,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(void) { 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; }
@@ -2689,6 +2664,46 @@ static void __console_unlock(void)
 	up_console_sem();
 }
 
+/**
+ * cons_print_dropped - Print 'dropped' message if required
+ * @desc:	Pointer to the output descriptor
+ *
+ * Prints the 'dropped' message info the output buffer if @desc->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 print into it at the beginning and move the resulting string
+ * just in front of the regular text buffer so that the message can
+ * be printed in one go.
+ *
+ * In case of a message this returns with @desc->outbuf and @desc->len
+ * updated. If no message is required then @desc is not modified.
+ */
+static void cons_print_dropped(struct cons_outbuf_desc *desc)
+{
+	struct cons_text_buf *txtbuf = desc->txtbuf;
+	size_t len;
+
+	if (!desc->dropped || desc->extmsg)
+		return;
+
+	if (WARN_ON_ONCE(desc->outbuf != txtbuf->text))
+		return;
+
+	/* Print it into ext_text which is unused */
+	len = snprintf(txtbuf->ext_text, DROPPED_TEXT_MAX,
+		       "** %lu printk messages dropped **\n", desc->dropped);
+	desc->dropped = 0;
+
+	/* Copy it just below text so it goes out with one write */
+	memcpy(txtbuf->text - len, txtbuf->ext_text, len);
+
+	/* Update the descriptor */
+	desc->len += len;
+	desc->outbuf -= len;
+}
+
 
 /**
  * cons_fill_outbuf - Fill the output buffer with the next record
@@ -2742,17 +2757,26 @@ static bool cons_fill_outbuf(struct console *con, struct cons_outbuf_desc *desc)
 	}
 
 	if (desc->extmsg) {
+		/*
+		 * Extended messages do not require "dropped" message
+		 * as that can be seen from the sequence number
+		 */
 		write_text = txtbuf->ext_text;
 		len = info_print_ext_header(write_text, CONSOLE_EXT_LOG_MAX, r.info);
 		len += msg_print_ext_body(write_text + len, CONSOLE_EXT_LOG_MAX - len,
 					  &r.text_buf[0], r.info->text_len, &r.info->dev_info);
+		desc->len = len;
+		desc->outbuf = write_text;
 	} else {
-		write_text = txtbuf->text;
 		len = record_print_text(&r, console_msg_format & MSG_FORMAT_SYSLOG, printk_time);
+
+		desc->len = len;
+		desc->outbuf = txtbuf->text;
+		desc->dropped = con->dropped;
+		cons_print_dropped(desc);
+		con->dropped = desc->dropped;
 	}
 
-	desc->len = len;
-	desc->outbuf = write_text;
 	return true;
 }
 
@@ -2805,8 +2829,10 @@ static bool console_emit_next_record(struct console *con, struct cons_text_buf *
 	printk_safe_enter_irqsave(flags);
 	console_lock_spinning_enable();
 
-	stop_critical_timings();	/* don't trace print latency */
-	call_console_driver(con, desc.outbuf, desc.len, extmsg ? NULL : txtbuf->dropped_text);
+	/* don't trace print latency */
+	stop_critical_timings();
+	/* Write everything out to the hardware */
+	con->write(con, desc.outbuf, desc.len);
 	start_critical_timings();
 
 	con->seq++;
-- 
2.30.2

On (22/09/24 02:10), John Ogness wrote:
[..]
> +/**
> + * cons_print_dropped - Print 'dropped' message if required
> + * @desc:	Pointer to the output descriptor
> + *
> + * Prints the 'dropped' message info the output buffer if @desc->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 print into it at the beginning and move the resulting string
> + * just in front of the regular text buffer so that the message can
> + * be printed in one go.
> + *
> + * In case of a message this returns with @desc->outbuf and @desc->len
> + * updated. If no message is required then @desc is not modified.
> + */
> +static void cons_print_dropped(struct cons_outbuf_desc *desc)

A silly nit: as far as I can tell printk API uses console_foo for
naming, so my personal preference would be to spell console_ instead
of cons_ (in this and in previous patches).

> +{
> +	struct cons_text_buf *txtbuf = desc->txtbuf;
> +	size_t len;
> +
> +	if (!desc->dropped || desc->extmsg)
> +		return;
> +
> +	if (WARN_ON_ONCE(desc->outbuf != txtbuf->text))
> +		return;
> +
> +	/* Print it into ext_text which is unused */
> +	len = snprintf(txtbuf->ext_text, DROPPED_TEXT_MAX,
> +		       "** %lu printk messages dropped **\n", desc->dropped);
> +	desc->dropped = 0;
> +
> +	/* Copy it just below text so it goes out with one write */
> +	memcpy(txtbuf->text - len, txtbuf->ext_text, len);
> +
> +	/* Update the descriptor */
> +	desc->len += len;
> +	desc->outbuf -= len;
> +}
> +
>  

An even sillier nit: extra blank line /* can't help noticing it every time
I read this function :) */

On (22/09/24 02:10), John Ogness wrote:
> +/**
> + * cons_print_dropped - Print 'dropped' message if required
> + * @desc:	Pointer to the output descriptor
> + *
> + * Prints the 'dropped' message info the output buffer if @desc->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 print into it at the beginning and move the resulting string
> + * just in front of the regular text buffer so that the message can
> + * be printed in one go.
> + *
> + * In case of a message this returns with @desc->outbuf and @desc->len
> + * updated. If no message is required then @desc is not modified.
> + */
> +static void cons_print_dropped(struct cons_outbuf_desc *desc)
> +{
> +	struct cons_text_buf *txtbuf = desc->txtbuf;
> +	size_t len;
> +
> +	if (!desc->dropped || desc->extmsg)
> +		return;
> +
> +	if (WARN_ON_ONCE(desc->outbuf != txtbuf->text))
> +		return;
> +
> +	/* Print it into ext_text which is unused */
> +	len = snprintf(txtbuf->ext_text, DROPPED_TEXT_MAX,
> +		       "** %lu printk messages dropped **\n", desc->dropped);
> +	desc->dropped = 0;
> +
> +	/* Copy it just below text so it goes out with one write */
> +	memcpy(txtbuf->text - len, txtbuf->ext_text, len);
> +
> +	/* Update the descriptor */
> +	desc->len += len;
> +	desc->outbuf -= len;

Oh, hmm. This does not look to me as a simplification. Quite
the opposite, moving cons_text_buf::text pointer to point to
cons_text_buf::text - strlen("... dropped messages...") looks
somewhat fragile.

Is printing 'dropped' and outbuf messages in one go such an
important feature?

On 2022-09-26, Sergey Senozhatsky <senozhatsky@chromium.org> wrote:
> On (22/09/24 02:10), John Ogness wrote:
>> +/**
>> + * cons_print_dropped - Print 'dropped' message if required
>> + * @desc:	Pointer to the output descriptor
>> + *
>> + * Prints the 'dropped' message info the output buffer if @desc->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 print into it at the beginning and move the resulting string
>> + * just in front of the regular text buffer so that the message can
>> + * be printed in one go.
>> + *
>> + * In case of a message this returns with @desc->outbuf and @desc->len
>> + * updated. If no message is required then @desc is not modified.
>> + */
>> +static void cons_print_dropped(struct cons_outbuf_desc *desc)
>> +{
>> +	struct cons_text_buf *txtbuf = desc->txtbuf;
>> +	size_t len;
>> +
>> +	if (!desc->dropped || desc->extmsg)
>> +		return;
>> +
>> +	if (WARN_ON_ONCE(desc->outbuf != txtbuf->text))
>> +		return;
>> +
>> +	/* Print it into ext_text which is unused */
>> +	len = snprintf(txtbuf->ext_text, DROPPED_TEXT_MAX,
>> +		       "** %lu printk messages dropped **\n", desc->dropped);
>> +	desc->dropped = 0;
>> +
>> +	/* Copy it just below text so it goes out with one write */
>> +	memcpy(txtbuf->text - len, txtbuf->ext_text, len);
>> +
>> +	/* Update the descriptor */
>> +	desc->len += len;
>> +	desc->outbuf -= len;
>
> Oh, hmm. This does not look to me as a simplification. Quite
> the opposite, moving cons_text_buf::text pointer to point to
> cons_text_buf::text - strlen("... dropped messages...") looks
> somewhat fragile.

It relies on @ext_text and @text being packed together, which yes, may
be fragile. As an alternative we could memcpy the message text (@text)
to the end of the dropped message text. There would be enough room.

Generally speaking, the dropped text will be less text to copy. But
since dropped messages are rare anyway, it might be worth copying more
data so that the code is not fragile. It would also allow us to remove
the __no_randomize_layout in "struct cons_text_buf".

If the end of cons_print_dropped was changed to:

        memcpy(txtbuf->ext_text + len, txtbuf->text, desc->len);
        desc->len += len;
        desc->outbuf = txtbuf->ext_text;

Would that be OK for you?

> Is printing 'dropped' and outbuf messages in one go such an
> important feature?

I think it is a nice simplification. With the cons_text_buf, it makes it
quite easy to implement.

John

On Mon 2022-09-26 10:00:36, John Ogness wrote:
> On 2022-09-26, Sergey Senozhatsky <senozhatsky@chromium.org> wrote:
> > On (22/09/24 02:10), John Ogness wrote:
> >> +/**
> >> + * cons_print_dropped - Print 'dropped' message if required
> >> + * @desc:	Pointer to the output descriptor
> >> + *
> >> + * Prints the 'dropped' message info the output buffer if @desc->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 print into it at the beginning and move the resulting string
> >> + * just in front of the regular text buffer so that the message can
> >> + * be printed in one go.
> >> + *
> >> + * In case of a message this returns with @desc->outbuf and @desc->len
> >> + * updated. If no message is required then @desc is not modified.
> >> + */
> >> +static void cons_print_dropped(struct cons_outbuf_desc *desc)
> >> +{
> >> +	struct cons_text_buf *txtbuf = desc->txtbuf;
> >> +	size_t len;
> >> +
> >> +	if (!desc->dropped || desc->extmsg)
> >> +		return;
> >> +
> >> +	if (WARN_ON_ONCE(desc->outbuf != txtbuf->text))
> >> +		return;
> >> +
> >> +	/* Print it into ext_text which is unused */
> >> +	len = snprintf(txtbuf->ext_text, DROPPED_TEXT_MAX,
> >> +		       "** %lu printk messages dropped **\n", desc->dropped);
> >> +	desc->dropped = 0;
> >> +
> >> +	/* Copy it just below text so it goes out with one write */
> >> +	memcpy(txtbuf->text - len, txtbuf->ext_text, len);
> >> +
> >> +	/* Update the descriptor */
> >> +	desc->len += len;
> >> +	desc->outbuf -= len;
> >
> > Oh, hmm. This does not look to me as a simplification. Quite
> > the opposite, moving cons_text_buf::text pointer to point to
> > cons_text_buf::text - strlen("... dropped messages...") looks
> > somewhat fragile.
> 
> It relies on @ext_text and @text being packed together, which yes, may
> be fragile.

Yes, it is a nasty hack ;-)

I suggest to increase CONSOLE_LOG_MAX to 2048,
define LOG_LINE_MAX as 1024, and use the buffer for both
dropped message and normal message.

It would simplify the code. Also it would make enough
space for more potential line headers needed by more
lines in one record.

It would require moving the normal message to make a space for
the dropped messages. But the dropping should be rare. And we
do a lot of moving in record_print_text() anyway.

I think that I was against increasing the buffer size some time ago.
I was worried about small devices. But I think that the patch
just increased the buffer size without any bug report so that
the justification was weak.

But simplifying the code looks like a good justification to me.
And I really like the removal of the extra buffer.

Best Regards,
Petr

On (22/09/26 10:00), John Ogness wrote:
> > Oh, hmm. This does not look to me as a simplification. Quite
> > the opposite, moving cons_text_buf::text pointer to point to
> > cons_text_buf::text - strlen("... dropped messages...") looks
> > somewhat fragile.
> 
> It relies on @ext_text and @text being packed together, which yes, may
> be fragile.

Right, and this assumption can be broken by both internal and external
sources: new gcc/clang plugins, config options, etc.

> As an alternative we could memcpy the message text (@text)
> to the end of the dropped message text. There would be enough room.
> 
> Generally speaking, the dropped text will be less text to copy. But
> since dropped messages are rare anyway, it might be worth copying more
> data so that the code is not fragile. It would also allow us to remove
> the __no_randomize_layout in "struct cons_text_buf".

Agreed.

> If the end of cons_print_dropped was changed to:
> 
>         memcpy(txtbuf->ext_text + len, txtbuf->text, desc->len);
>         desc->len += len;
>         desc->outbuf = txtbuf->ext_text;
> 
> Would that be OK for you?

Yes, this looks solid (nothing should be able to break it and cause
mem corruptions).