Hi,
This is v3 of a series to cleanup console buffer handling and
prepare for code sharing with the upcoming threaded/atomic
consoles. v2 is here [0].
The main purpose of the series is to introduce 2 new lockless
functions to handle all console formatting of printk messages. These
functions can then be used from any context, which is important for
the upcoming threaded/atomic consoles. The series also helps to
cleanup some of the internal printk interfaces and cleanly separate
formatting code from outputting code.
Changes since v2:
- Put size limit macros and definitions of structs console_buffers
and console_message in printk/internal.h instead of
linux/console.h.
- Provide a better description for @dropped field of struct console.
(Only a small change in patch 3/6. I kept Petr's Reviewed-by tag.)
- Move the static struct console_buffers inside
console_emit_next_record() since this function will not be used by
the threaded/atomic consoles.
- Rename various functions and struct fields:
msg_print_dropped() -> console_prepend_dropped()
console_buffers.ext_text -> console_buffers.outbuf
console_buffers.text -> console_buffers.scratchbuf
- console_buffers.outbuf is always the output buffer.
- Change struct console_message fields:
removed: char *outbuf
removed: bool is_extmsg
added: u64 outbuf_seq
added: unsigned long dropped
- All struct console_message fields are now output fields. No input
fields.
- Implement console_prepend_dropped() as suggested by pmladek: shift
existing message and insert dropped message.
- For console_get_next_message():
add all input variables as arguments
do not rely on locking (no @console argument)
do not prepend "dropped messages", let the caller deal with that
implement as suggested by pmladek: use different buffers for
ringbuffer reading so that @outbuf is always the output buffer
in the end
- Do not use struct console_buffers for devkmsg. (It is not a
console).
John Ogness
[0] https://lore.kernel.org/lkml/[email protected]
John Ogness (4):
printk: move size limit macros into internal.h
printk: introduce struct console_buffers
printk: introduce console_get_next_message() and console_message
printk: introduce console_prepend_dropped() for dropped messages
Thomas Gleixner (2):
console: Use BIT() macros for @flags values
console: Document struct console
include/linux/console.h | 100 ++++++++++++-----
include/linux/printk.h | 2 -
kernel/printk/internal.h | 45 ++++++++
kernel/printk/printk.c | 237 +++++++++++++++++++++++----------------
4 files changed, 260 insertions(+), 124 deletions(-)
base-commit: 6b2b0d839acaa84f05a77184370f793752e786e9
--
2.30.2
Code for performing the console output is intermixed with code
that is formatting the output for that console. Introduce a new
helper function console_get_next_message() to handle the reading
and formatting of the console text. The helper does not require
any locking so that in the future it can be used for other console
printing contexts as well.
This also introduces a new struct console_message to wrap the
struct console_buffers adding meta-data about its contents. This
allows users of console_get_next_message() to receive all relevant
information about the message that was read and formatted.
The reason a wrapper struct is introduced instead of adding the
meta-data to struct console_buffers is because the upcoming atomic
consoles will need per-cpu and per-context console_buffers. It
would not make sense to make the meta-data also per-cpu and
per-context as that data can be easily stored on the stack of the
console printing context.
Signed-off-by: John Ogness <[email protected]>
---
kernel/printk/internal.h | 16 ++++++
kernel/printk/printk.c | 118 +++++++++++++++++++++++++++------------
2 files changed, 97 insertions(+), 37 deletions(-)
diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
index f5ebbd392fee..4f2eb8c470bc 100644
--- a/kernel/printk/internal.h
+++ b/kernel/printk/internal.h
@@ -91,3 +91,19 @@ struct console_buffers {
char outbuf[CONSOLE_EXT_LOG_MAX];
char scratchbuf[LOG_LINE_MAX];
};
+
+/**
+ * console_message - Container for a prepared console message.
+ * @cbufs: Console buffers used to prepare the message.
+ * @outbuf_len: The length of prepared text in @cbufs->outbuf to output. This
+ * does not count the terminator. A value of 0 means there is
+ * nothing to output and this record should be skipped.
+ * @outbuf_seq: The sequence number of the record used for @cbufs->outbuf.
+ * @dropped: The number of dropped records from reading @outbuf_seq.
+ */
+struct console_message {
+ struct console_buffers *cbufs;
+ unsigned int outbuf_len;
+ u64 outbuf_seq;
+ unsigned long dropped;
+};
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 2e5e2eda1fa1..7cac636600f8 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2725,34 +2725,34 @@ static void __console_unlock(void)
}
/*
- * Print one record for the given console. The record printed is whatever
- * record is the next available record for the given console.
+ * Read and format the specified record (or a later record if the specified
+ * record is not available).
*
- * @handover will be set to true if a printk waiter has taken over the
- * console_lock, in which case the caller is no longer holding both the
- * console_lock and the SRCU read lock. Otherwise it is set to false.
+ * @cmsg will contain the formatted result. @cmsg->cbufs must point to a
+ * struct console_buffers.
*
- * @cookie is the cookie from the SRCU read lock.
+ * @seq is the record to read and format. If it is not available, the next
+ * valid record is read.
*
- * Returns false if the given console has no next record to print, otherwise
- * true.
+ * @is_extended specifies the message should be formatted for extended
+ * console output.
*
- * Requires the console_lock and the SRCU read lock.
+ * Returns false if no record is available. Otherwise true and all fields
+ * of @cmsg are valid. (See the documentation of struct console_message
+ * for information about the @cmsg fields.)
*/
-static bool console_emit_next_record(struct console *con, bool *handover, int cookie)
-{
- bool is_extended = console_srcu_read_flags(con) & CON_EXTENDED;
- static char dropped_text[DROPPED_TEXT_MAX];
- static struct console_buffers cbufs;
- const size_t scratchbuf_sz = sizeof(cbufs.scratchbuf);
- const size_t outbuf_sz = sizeof(cbufs.outbuf);
- char *scratchbuf = &cbufs.scratchbuf[0];
- char *outbuf = &cbufs.outbuf[0];
+static bool console_get_next_message(struct console_message *cmsg, u64 seq,
+ bool is_extended)
+{
+ struct console_buffers *cbufs = cmsg->cbufs;
+ const size_t scratchbuf_sz = sizeof(cbufs->scratchbuf);
+ const size_t outbuf_sz = sizeof(cbufs->outbuf);
+ char *scratchbuf = &cbufs->scratchbuf[0];
+ char *outbuf = &cbufs->outbuf[0];
static int panic_console_dropped;
struct printk_info info;
struct printk_record r;
- unsigned long flags;
- size_t len;
+ size_t len = 0;
/*
* Formatting extended messages requires a separate buffer, so use the
@@ -2766,33 +2766,77 @@ static bool console_emit_next_record(struct console *con, bool *handover, int co
else
prb_rec_init_rd(&r, &info, outbuf, outbuf_sz);
- *handover = false;
-
- if (!prb_read_valid(prb, con->seq, &r))
+ if (!prb_read_valid(prb, seq, &r))
return false;
- if (con->seq != r.info->seq) {
- con->dropped += r.info->seq - con->seq;
- con->seq = r.info->seq;
- if (panic_in_progress() && panic_console_dropped++ > 10) {
- suppress_panic_printk = 1;
- pr_warn_once("Too many dropped messages. Suppress messages on non-panic CPUs to prevent livelock.\n");
- }
+ cmsg->outbuf_seq = r.info->seq;
+ cmsg->dropped = r.info->seq - seq;
+
+ /*
+ * Check for dropped messages in panic here so that printk
+ * suppression can occur as early as possible if necessary.
+ */
+ if (cmsg->dropped &&
+ panic_in_progress() &&
+ panic_console_dropped++ > 10) {
+ suppress_panic_printk = 1;
+ pr_warn_once("Too many dropped messages. Suppress messages on non-panic CPUs to prevent livelock.\n");
}
/* Skip record that has level above the console loglevel. */
- if (suppress_message_printing(r.info->level)) {
- con->seq++;
- goto skip;
- }
+ if (suppress_message_printing(r.info->level))
+ goto out;
if (is_extended) {
len = info_print_ext_header(outbuf, outbuf_sz, r.info);
len += msg_print_ext_body(outbuf + len, outbuf_sz - len,
- &r.text_buf[0], r.info->text_len, &r.info->dev_info);
+ r.text_buf, r.info->text_len, &r.info->dev_info);
} else {
len = record_print_text(&r, console_msg_format & MSG_FORMAT_SYSLOG, printk_time);
}
+out:
+ 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.
+ *
+ * @handover will be set to true if a printk waiter has taken over the
+ * console_lock, in which case the caller is no longer holding both the
+ * console_lock and the SRCU read lock. Otherwise it is set to false.
+ *
+ * @cookie is the cookie from the SRCU read lock.
+ *
+ * Returns false if the given console has no next record to print, otherwise
+ * true.
+ *
+ * Requires the console_lock and the SRCU read lock.
+ */
+static bool console_emit_next_record(struct console *con, bool *handover, int cookie)
+{
+ bool is_extended = console_srcu_read_flags(con) & CON_EXTENDED;
+ static char dropped_text[DROPPED_TEXT_MAX];
+ static struct console_buffers cbufs;
+ static struct console_message cmsg = {
+ .cbufs = &cbufs,
+ };
+ char *outbuf = &cbufs.outbuf[0];
+ unsigned long flags;
+
+ *handover = false;
+
+ if (!console_get_next_message(&cmsg, con->seq, is_extended))
+ return false;
+
+ con->dropped += cmsg.dropped;
+
+ /* Skip messages of formatted length 0. */
+ if (cmsg.outbuf_len == 0) {
+ con->seq = cmsg.outbuf_seq + 1;
+ goto skip;
+ }
/*
* While actively printing out messages, if another printk()
@@ -2808,11 +2852,11 @@ static bool console_emit_next_record(struct console *con, bool *handover, int co
console_lock_spinning_enable();
stop_critical_timings(); /* don't trace print latency */
- call_console_driver(con, outbuf, len,
+ call_console_driver(con, outbuf, cmsg.outbuf_len,
is_extended ? NULL : dropped_text);
start_critical_timings();
- con->seq++;
+ con->seq = cmsg.outbuf_seq + 1;
*handover = console_lock_spinning_disable_and_check(cookie);
printk_safe_exit_irqrestore(flags);
--
2.30.2
Currently "dropped messages" are separately printed immediately
before printing the printk message. Since normal consoles are
now using an output buffer that is much larger than previously,
the "dropped message" could be prepended to the printk message
and output in a single call.
Introduce a helper function console_prepend_dropped() to prepend
an existing message with a "dropped message". This simplifies
the code by allowing all message formatting to be handled
together and then only requires a single write() call to output
the full message. And since this helper does not require any
locking, it can be used in the future for other console printing
contexts as well.
Signed-off-by: John Ogness <[email protected]>
---
kernel/printk/internal.h | 4 --
kernel/printk/printk.c | 84 ++++++++++++++++++++++++++--------------
2 files changed, 55 insertions(+), 33 deletions(-)
diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
index 4f2eb8c470bc..b0ca59e6edad 100644
--- a/kernel/printk/internal.h
+++ b/kernel/printk/internal.h
@@ -26,9 +26,6 @@ int devkmsg_sysctl_set_loglvl(struct ctl_table *table, int write,
/* the maximum size of a formatted extended record */
#define CONSOLE_EXT_LOG_MAX 8192
-/* the maximum size for a dropped text message */
-#define DROPPED_TEXT_MAX 64
-
/* the maximum size allowed to be reserved for a record */
#define LOG_LINE_MAX (CONSOLE_LOG_MAX - PREFIX_MAX)
@@ -68,7 +65,6 @@ u16 printk_parse_prefix(const char *text, int *level,
#define CONSOLE_LOG_MAX 0
#define CONSOLE_EXT_LOG_MAX 0
-#define DROPPED_TEXT_MAX 0
#define LOG_LINE_MAX 0
/*
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 7cac636600f8..f0d9c88e434f 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1995,27 +1995,6 @@ static int console_trylock_spinning(void)
return 1;
}
-/*
- * Call the specified console driver, asking it to write out the specified
- * text and length. If @dropped_text is non-NULL and any records have been
- * dropped, a dropped message will be written out first.
- */
-static void call_console_driver(struct console *con, const char *text, size_t len,
- char *dropped_text)
-{
- size_t dropped_len;
-
- if (con->dropped && dropped_text) {
- dropped_len = snprintf(dropped_text, DROPPED_TEXT_MAX,
- "** %lu printk messages dropped **\n",
- con->dropped);
- con->dropped = 0;
- con->write(con, dropped_text, dropped_len);
- }
-
- con->write(con, text, len);
-}
-
/*
* Recursion is tracked separately on each CPU. If NMIs are supported, an
* additional NMI context per CPU is also separately tracked. Until per-CPU
@@ -2395,10 +2374,6 @@ static ssize_t msg_print_ext_body(char *buf, size_t size,
struct dev_printk_info *dev_info) { return 0; }
static void console_lock_spinning_enable(void) { }
static int console_lock_spinning_disable_and_check(int cookie) { return 0; }
-static void call_console_driver(struct console *con, const char *text, size_t len,
- char *dropped_text)
-{
-}
static bool suppress_message_printing(int level) { return false; }
static bool pr_flush(int timeout_ms, bool reset_on_progress) { return true; }
static bool __pr_flush(struct console *con, int timeout_ms, bool reset_on_progress) { return true; }
@@ -2724,6 +2699,50 @@ static void __console_unlock(void)
up_console_sem();
}
+/*
+ * Prepend the message in @cmsg->cbufs->outbuf with a "dropped message". This
+ * is achieved by shifting the existing message over and inserting the dropped
+ * message.
+ *
+ * @cmsg is the console message to prepend.
+ *
+ * @dropped is the dropped count to report in the dropped message.
+ *
+ * If the message text in @cmsg->cbufs->outbuf does not have enough space for
+ * the dropped message, the message text will be sufficiently truncated.
+ *
+ * If @cmsg->cbufs->outbuf is modified, @cmsg->outbuf_len is updated.
+ */
+static void console_prepend_dropped(struct console_message *cmsg, unsigned long dropped)
+{
+ struct console_buffers *cbufs = cmsg->cbufs;
+ const size_t scratchbuf_sz = sizeof(cbufs->scratchbuf);
+ const size_t outbuf_sz = sizeof(cbufs->outbuf);
+ char *scratchbuf = &cbufs->scratchbuf[0];
+ char *outbuf = &cbufs->outbuf[0];
+ size_t len;
+
+ len = snprintf(scratchbuf, scratchbuf_sz,
+ "** %lu printk messages dropped **\n", dropped);
+
+ /*
+ * Make sure outbuf is sufficiently large before prepending. Space
+ * for a terminator is also counted in case truncation occurs.
+ */
+ if (WARN_ON_ONCE(len + 1 >= outbuf_sz))
+ return;
+
+ if (cmsg->outbuf_len + len >= outbuf_sz) {
+ /* Truncate the message, but keep it terminated. */
+ cmsg->outbuf_len = outbuf_sz - (len + 1);
+ outbuf[cmsg->outbuf_len] = 0;
+ }
+
+ memmove(outbuf + len, outbuf, cmsg->outbuf_len + 1);
+ memcpy(outbuf, scratchbuf, len);
+ cmsg->outbuf_len += len;
+}
+
/*
* Read and format the specified record (or a later record if the specified
* record is not available).
@@ -2817,7 +2836,6 @@ static bool console_get_next_message(struct console_message *cmsg, u64 seq,
static bool console_emit_next_record(struct console *con, bool *handover, int cookie)
{
bool is_extended = console_srcu_read_flags(con) & CON_EXTENDED;
- static char dropped_text[DROPPED_TEXT_MAX];
static struct console_buffers cbufs;
static struct console_message cmsg = {
.cbufs = &cbufs,
@@ -2838,6 +2856,11 @@ static bool console_emit_next_record(struct console *con, bool *handover, int co
goto skip;
}
+ if (con->dropped && !is_extended) {
+ console_prepend_dropped(&cmsg, con->dropped);
+ con->dropped = 0;
+ }
+
/*
* While actively printing out messages, if another printk()
* were to occur on another CPU, it may wait for this one to
@@ -2851,9 +2874,12 @@ static bool console_emit_next_record(struct console *con, bool *handover, int co
printk_safe_enter_irqsave(flags);
console_lock_spinning_enable();
- stop_critical_timings(); /* don't trace print latency */
- call_console_driver(con, outbuf, cmsg.outbuf_len,
- is_extended ? NULL : dropped_text);
+ /* Do not trace print latency. */
+ stop_critical_timings();
+
+ /* Write everything out to the hardware. */
+ con->write(con, outbuf, cmsg.outbuf_len);
+
start_critical_timings();
con->seq = cmsg.outbuf_seq + 1;
--
2.30.2
On 2022-12-21, John Ogness <[email protected]> wrote:
> +static bool console_emit_next_record(struct console *con, bool *handover, int cookie)
> +{
> + bool is_extended = console_srcu_read_flags(con) & CON_EXTENDED;
> + static char dropped_text[DROPPED_TEXT_MAX];
> + static struct console_buffers cbufs;
> + static struct console_message cmsg = {
> + .cbufs = &cbufs,
> + };
@cmsg should not be static. The whole point of the console_message
wrapper struct is so that it can sit on the stack.
John Ogness
On Wed 2022-12-21 21:33:03, John Ogness wrote:
> Code for performing the console output is intermixed with code
> that is formatting the output for that console. Introduce a new
> helper function console_get_next_message() to handle the reading
> and formatting of the console text. The helper does not require
> any locking so that in the future it can be used for other console
> printing contexts as well.
>
> This also introduces a new struct console_message to wrap the
> struct console_buffers adding meta-data about its contents. This
> allows users of console_get_next_message() to receive all relevant
> information about the message that was read and formatted.
>
> The reason a wrapper struct is introduced instead of adding the
> meta-data to struct console_buffers is because the upcoming atomic
> consoles will need per-cpu and per-context console_buffers. It
> would not make sense to make the meta-data also per-cpu and
> per-context as that data can be easily stored on the stack of the
> console printing context.
>
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 2e5e2eda1fa1..7cac636600f8 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -2725,34 +2725,34 @@ static void __console_unlock(void)
> }
>
> /*
> - * Print one record for the given console. The record printed is whatever
> - * record is the next available record for the given console.
> + * Read and format the specified record (or a later record if the specified
> + * record is not available).
> *
> - * @handover will be set to true if a printk waiter has taken over the
> - * console_lock, in which case the caller is no longer holding both the
> - * console_lock and the SRCU read lock. Otherwise it is set to false.
> + * @cmsg will contain the formatted result. @cmsg->cbufs must point to a
> + * struct console_buffers.
> *
> - * @cookie is the cookie from the SRCU read lock.
> + * @seq is the record to read and format. If it is not available, the next
> + * valid record is read.
> *
> - * Returns false if the given console has no next record to print, otherwise
> - * true.
> + * @is_extended specifies the message should be formatted for extended
> + * console output.
> *
> - * Requires the console_lock and the SRCU read lock.
> + * Returns false if no record is available. Otherwise true and all fields
> + * of @cmsg are valid. (See the documentation of struct console_message
> + * for information about the @cmsg fields.)
> */
> -static bool console_emit_next_record(struct console *con, bool *handover, int cookie)
> -{
> - bool is_extended = console_srcu_read_flags(con) & CON_EXTENDED;
> - static char dropped_text[DROPPED_TEXT_MAX];
> - static struct console_buffers cbufs;
> - const size_t scratchbuf_sz = sizeof(cbufs.scratchbuf);
> - const size_t outbuf_sz = sizeof(cbufs.outbuf);
> - char *scratchbuf = &cbufs.scratchbuf[0];
> - char *outbuf = &cbufs.outbuf[0];
> +static bool console_get_next_message(struct console_message *cmsg, u64 seq,
> + bool is_extended)
> +{
> + struct console_buffers *cbufs = cmsg->cbufs;
> + const size_t scratchbuf_sz = sizeof(cbufs->scratchbuf);
> + const size_t outbuf_sz = sizeof(cbufs->outbuf);
> + char *scratchbuf = &cbufs->scratchbuf[0];
> + char *outbuf = &cbufs->outbuf[0];
> static int panic_console_dropped;
> struct printk_info info;
> struct printk_record r;
> - unsigned long flags;
> - size_t len;
> + size_t len = 0;
>
> /*
> * Formatting extended messages requires a separate buffer, so use the
> @@ -2766,33 +2766,77 @@ static bool console_emit_next_record(struct console *con, bool *handover, int co
> else
> prb_rec_init_rd(&r, &info, outbuf, outbuf_sz);
>
> - *handover = false;
> -
> - if (!prb_read_valid(prb, con->seq, &r))
> + if (!prb_read_valid(prb, seq, &r))
> return false;
>
> - if (con->seq != r.info->seq) {
> - con->dropped += r.info->seq - con->seq;
> - con->seq = r.info->seq;
> - if (panic_in_progress() && panic_console_dropped++ > 10) {
> - suppress_panic_printk = 1;
> - pr_warn_once("Too many dropped messages. Suppress messages on non-panic CPUs to prevent livelock.\n");
> - }
> + cmsg->outbuf_seq = r.info->seq;
> + cmsg->dropped = r.info->seq - seq;
> +
> + /*
> + * Check for dropped messages in panic here so that printk
> + * suppression can occur as early as possible if necessary.
> + */
> + if (cmsg->dropped &&
> + panic_in_progress() &&
> + panic_console_dropped++ > 10) {
> + suppress_panic_printk = 1;
> + pr_warn_once("Too many dropped messages. Suppress messages on non-panic CPUs to prevent livelock.\n");
> }
>
> /* Skip record that has level above the console loglevel. */
> - if (suppress_message_printing(r.info->level)) {
> - con->seq++;
> - goto skip;
> - }
> + if (suppress_message_printing(r.info->level))
> + goto out;
>
> if (is_extended) {
> len = info_print_ext_header(outbuf, outbuf_sz, r.info);
> len += msg_print_ext_body(outbuf + len, outbuf_sz - len,
> - &r.text_buf[0], r.info->text_len, &r.info->dev_info);
> + r.text_buf, r.info->text_len, &r.info->dev_info);
This probably was not intended.
If you agree then I could revert this change when pushing.
Or feel free to send respin of this patch.
> } else {
> len = record_print_text(&r, console_msg_format & MSG_FORMAT_SYSLOG, printk_time);
> }
> +out:
> + cmsg->outbuf_len = len;
> + return true;
> +}
Otherwise, it looks good:
Reviewed-by: Petr Mladek <[email protected]>
Best Regards,
Petr
On Wed 2022-12-21 21:33:04, John Ogness wrote:
> Currently "dropped messages" are separately printed immediately
> before printing the printk message. Since normal consoles are
> now using an output buffer that is much larger than previously,
> the "dropped message" could be prepended to the printk message
> and output in a single call.
>
> Introduce a helper function console_prepend_dropped() to prepend
> an existing message with a "dropped message". This simplifies
> the code by allowing all message formatting to be handled
> together and then only requires a single write() call to output
> the full message. And since this helper does not require any
> locking, it can be used in the future for other console printing
> contexts as well.
>
> Signed-off-by: John Ogness <[email protected]>
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -2724,6 +2699,50 @@ static void __console_unlock(void)
> up_console_sem();
> }
>
> +/*
> + * Prepend the message in @cmsg->cbufs->outbuf with a "dropped message". This
> + * is achieved by shifting the existing message over and inserting the dropped
> + * message.
> + *
> + * @cmsg is the console message to prepend.
> + *
> + * @dropped is the dropped count to report in the dropped message.
> + *
> + * If the message text in @cmsg->cbufs->outbuf does not have enough space for
> + * the dropped message, the message text will be sufficiently truncated.
> + *
> + * If @cmsg->cbufs->outbuf is modified, @cmsg->outbuf_len is updated.
> + */
> +static void console_prepend_dropped(struct console_message *cmsg, unsigned long dropped)
> +{
> + struct console_buffers *cbufs = cmsg->cbufs;
> + const size_t scratchbuf_sz = sizeof(cbufs->scratchbuf);
> + const size_t outbuf_sz = sizeof(cbufs->outbuf);
> + char *scratchbuf = &cbufs->scratchbuf[0];
> + char *outbuf = &cbufs->outbuf[0];
> + size_t len;
> +
> + len = snprintf(scratchbuf, scratchbuf_sz,
> + "** %lu printk messages dropped **\n", dropped);
> +
> + /*
> + * Make sure outbuf is sufficiently large before prepending. Space
> + * for a terminator is also counted in case truncation occurs.
> + */
> + if (WARN_ON_ONCE(len + 1 >= outbuf_sz))
> + return;
Strictly speaking, this should be:
if (WARN_ON_ONCE(len >= outbuf_sz))
return;
The trailing '\0' will fit into the buffer when len < outbuf_sz.
That said, the consoles would be almost unusable when we are anywhere close this
limit. Most messages would be truncated.
> +
> + if (cmsg->outbuf_len + len >= outbuf_sz) {
> + /* Truncate the message, but keep it terminated. */
> + cmsg->outbuf_len = outbuf_sz - (len + 1);
> + outbuf[cmsg->outbuf_len] = 0;
> + }
> +
> + memmove(outbuf + len, outbuf, cmsg->outbuf_len + 1);
> + memcxpy(outbuf, scratchbuf, len);
> + cmsg->outbuf_len += len;
> +}
> +
> /*
> * Read and format the specified record (or a later record if the specified
> * record is not available).
Otherwise, the change looks fine:
Reviewed-by: Petr Mladek <[email protected]>
Best Regards,
Petr
On 2022-12-21, John Ogness <[email protected]> wrote:
> +/**
> + * console_message - Container for a prepared console message.
This documentation is not included in the kerneldocs, but it should at
least be proper kerneldoc format. It should be:
* struct console_message - Container for a prepared console message.
John
On 2023-01-02, Petr Mladek <[email protected]> wrote:
>> +static void console_prepend_dropped(struct console_message *cmsg, unsigned long dropped)
>> +{
>> + struct console_buffers *cbufs = cmsg->cbufs;
>> + const size_t scratchbuf_sz = sizeof(cbufs->scratchbuf);
>> + const size_t outbuf_sz = sizeof(cbufs->outbuf);
>> + char *scratchbuf = &cbufs->scratchbuf[0];
>> + char *outbuf = &cbufs->outbuf[0];
>> + size_t len;
>> +
>> + len = snprintf(scratchbuf, scratchbuf_sz,
>> + "** %lu printk messages dropped **\n", dropped);
>> +
>> + /*
>> + * Make sure outbuf is sufficiently large before prepending. Space
>> + * for a terminator is also counted in case truncation occurs.
>> + */
>> + if (WARN_ON_ONCE(len + 1 >= outbuf_sz))
>> + return;
>
> Strictly speaking, this should be:
>
> if (WARN_ON_ONCE(len >= outbuf_sz))
> return;
>
> The trailing '\0' will fit into the buffer when len < outbuf_sz.
You are correct.
My concern was that if "@len = @outbuf_sz - 1", the entire message will
be truncated and you will only see the dropped messages text. I wanted
at least 1 character from the message to survive. ;-)
How about the commments:
/*
* Make sure outbuf is sufficiently large before prepending. Space
* for a terminator and at least 1 byte of the message is also
* checked in case truncation is needed.
*/
John
On Tue 2023-01-03 11:26:23, John Ogness wrote:
> On 2023-01-02, Petr Mladek <[email protected]> wrote:
> >> +static void console_prepend_dropped(struct console_message *cmsg, unsigned long dropped)
> >> +{
> >> + struct console_buffers *cbufs = cmsg->cbufs;
> >> + const size_t scratchbuf_sz = sizeof(cbufs->scratchbuf);
> >> + const size_t outbuf_sz = sizeof(cbufs->outbuf);
> >> + char *scratchbuf = &cbufs->scratchbuf[0];
> >> + char *outbuf = &cbufs->outbuf[0];
> >> + size_t len;
> >> +
> >> + len = snprintf(scratchbuf, scratchbuf_sz,
> >> + "** %lu printk messages dropped **\n", dropped);
> >> +
> >> + /*
> >> + * Make sure outbuf is sufficiently large before prepending. Space
> >> + * for a terminator is also counted in case truncation occurs.
> >> + */
> >> + if (WARN_ON_ONCE(len + 1 >= outbuf_sz))
> >> + return;
> >
> > Strictly speaking, this should be:
> >
> > if (WARN_ON_ONCE(len >= outbuf_sz))
> > return;
> >
> > The trailing '\0' will fit into the buffer when len < outbuf_sz.
>
> You are correct.
>
> My concern was that if "@len = @outbuf_sz - 1", the entire message will
> be truncated and you will only see the dropped messages text. I wanted
> at least 1 character from the message to survive. ;-)
I see.
> How about the commments:
>
> /*
> * Make sure outbuf is sufficiently large before prepending. Space
> * for a terminator and at least 1 byte of the message is also
> * checked in case truncation is needed.
> */
It is better than the original.
Well, what about making sure that something more useful is always
printed. For example:
/*
* Make sure outbuf is sufficiently large before prepending.
* Keep at least the prefix when the message has to be truncated.
* It is a rather theoretical problem when someone tries to
* use a minimalist buffer.
*/
if (WARN_ON_ONCE(len + PREFIX_MAX + 1 >= outbuf_sz))
return;
If we want to use this way. It would probably make sense to
rename PREFIX_MAX to CONSOLE_PREFIX_MAX.
Best Regards,
Petr
On 2023-01-03, Petr Mladek <[email protected]> wrote:
> Well, what about making sure that something more useful is always
> printed. For example:
>
> /*
> * Make sure outbuf is sufficiently large before prepending.
> * Keep at least the prefix when the message has to be truncated.
> * It is a rather theoretical problem when someone tries to
> * use a minimalist buffer.
> */
> if (WARN_ON_ONCE(len + PREFIX_MAX + 1 >= outbuf_sz))
> return;
I am fine with this. We won't see this warning anyway. Few lines would
ever be printed correctly if anyone ever tries to use a buffer so small.
> If we want to use this way. It would probably make sense to
> rename PREFIX_MAX to CONSOLE_PREFIX_MAX.
Actually, I would like to rename all of those limit macros to something
that makes more sense for the new code base:
CONSOLE_EXT_LOG_MAX -> CONSOLE_MESSAGE_MAX
CONSOLE_LOG_MAX -> SYSLOG_MESSAGE_MAX
LOG_LINE_MAX -> PRINTK_RECORD_MAX
PREFIX_MAX -> CONSOLE_PREFIX_MAX
I have a patch to do this ready, but I did not want to post it until we
are finished with the thread/atomic work.
John
On Tue 2023-01-03 11:08:27, John Ogness wrote:
> On 2022-12-21, John Ogness <[email protected]> wrote:
> > +/**
> > + * console_message - Container for a prepared console message.
>
> This documentation is not included in the kerneldocs, but it should at
> least be proper kerneldoc format. It should be:
>
> * struct console_message - Container for a prepared console message.
Great catch!
Best Regards,
Petr
On Thu 2022-12-22 16:47:39, John Ogness wrote:
> On 2022-12-21, John Ogness <[email protected]> wrote:
> > +static bool console_emit_next_record(struct console *con, bool *handover, int cookie)
> > +{
> > + bool is_extended = console_srcu_read_flags(con) & CON_EXTENDED;
> > + static char dropped_text[DROPPED_TEXT_MAX];
> > + static struct console_buffers cbufs;
> > + static struct console_message cmsg = {
> > + .cbufs = &cbufs,
> > + };
>
> @cmsg should not be static. The whole point of the console_message
> wrapper struct is so that it can sit on the stack.
Well, it might actually be better to keep it static for now.
It always points to static struct console_buffers cbufs anyway.
It would make sense to have it on stack only when it uses
different buffers.
Which brings the question. Does it makes sense to use
the same buffers by different struct console_message?
Will it be safe in any situation?
I did not want to complicate it yesterday. I think that
I have already proposed this. But this brings back
the question whether it makes sense to have two structures
at all.
I still think that it would be easier and even more safe
to put everything into struct console_message.
I mean to have:
struct console_message {
char buf[CONSOLE_EXT_LOG_MAX];
char scratch_buf[LOG_LINE_MAX];
unsigned int len;
u64 seq;
unsigned long dropped;
};
Best Regards,
Petr
On Tue 2023-01-03 14:50:23, John Ogness wrote:
> On 2023-01-03, Petr Mladek <[email protected]> wrote:
> > Well, what about making sure that something more useful is always
> > printed. For example:
> >
> > /*
> > * Make sure outbuf is sufficiently large before prepending.
> > * Keep at least the prefix when the message has to be truncated.
> > * It is a rather theoretical problem when someone tries to
> > * use a minimalist buffer.
> > */
> > if (WARN_ON_ONCE(len + PREFIX_MAX + 1 >= outbuf_sz))
> > return;
>
> I am fine with this. We won't see this warning anyway. Few lines would
> ever be printed correctly if anyone ever tries to use a buffer so small.
Yup.
> > If we want to use this way. It would probably make sense to
> > rename PREFIX_MAX to CONSOLE_PREFIX_MAX.
>
> Actually, I would like to rename all of those limit macros to something
> that makes more sense for the new code base:
>
> CONSOLE_EXT_LOG_MAX -> CONSOLE_MESSAGE_MAX
>
> CONSOLE_LOG_MAX -> SYSLOG_MESSAGE_MAX
Heh, we actually do not need this. The size of @scratchbuf
might be LOG_LINE_MAX/PRINTK_RECORD_MAX. The scratch buffer
is newly used only to read the plain message. The prefixes
are added to @outbuf.
> LOG_LINE_MAX -> PRINTK_RECORD_MAX
>
> PREFIX_MAX -> CONSOLE_PREFIX_MAX
I like this.
> I have a patch to do this ready, but I did not want to post it until we
> are finished with the thread/atomic work.
It would make sense to do this as part of this patchset. But I do not
want to delay it too much. Feel free to do it later.
Best Regards,
Petr
On 2023-01-03, Petr Mladek <[email protected]> wrote:
>> Actually, I would like to rename all of those limit macros to something
>> that makes more sense for the new code base:
>>
>> CONSOLE_EXT_LOG_MAX -> CONSOLE_MESSAGE_MAX
>>
>> CONSOLE_LOG_MAX -> SYSLOG_MESSAGE_MAX
>
> Heh, we actually do not need this. The size of @scratchbuf
> might be LOG_LINE_MAX/PRINTK_RECORD_MAX. The scratch buffer
> is newly used only to read the plain message. The prefixes
> are added to @outbuf.
>
>> LOG_LINE_MAX -> PRINTK_RECORD_MAX
The scratch buffer would become PRINTK_RECORD_MAX, but we still need
SYSLOG_MESSAGE_MAX for the kmalloc's syslog buffers. Unless you think it
is OK to kmalloc 8KB instead of 1KB for the syslog calls. Then yes, we
do not need SYSLOG_MESSAGE_MAX.
John
On 2023-01-03, Petr Mladek <[email protected]> wrote:
> On Thu 2022-12-22 16:47:39, John Ogness wrote:
>> On 2022-12-21, John Ogness <[email protected]> wrote:
>> > +static bool console_emit_next_record(struct console *con, bool *handover, int cookie)
>> > +{
>> > + bool is_extended = console_srcu_read_flags(con) & CON_EXTENDED;
>> > + static char dropped_text[DROPPED_TEXT_MAX];
>> > + static struct console_buffers cbufs;
>> > + static struct console_message cmsg = {
>> > + .cbufs = &cbufs,
>> > + };
>>
>> @cmsg should not be static. The whole point of the console_message
>> wrapper struct is so that it can sit on the stack.
>
> Well, it might actually be better to keep it static for now.
> It always points to static struct console_buffers cbufs anyway.
>
> It would make sense to have it on stack only when it uses
> different buffers.
I think we should avoid making things static when it serves no purpose.
> Which brings the question. Does it makes sense to use
> the same buffers by different struct console_message?
> Will it be safe in any situation?
>
> I did not want to complicate it yesterday. I think that
> I have already proposed this. But this brings back
> the question whether it makes sense to have two structures
> at all.
>
> I still think that it would be easier and even more safe
> to put everything into struct console_message.
>
> I mean to have:
>
> struct console_message {
> char buf[CONSOLE_EXT_LOG_MAX];
> char scratch_buf[LOG_LINE_MAX];
> unsigned int len;
> u64 seq;
> unsigned long dropped;
> };
The current atomic console proposal allocates 1x cbuf per-cpu and 4x
meta-data per-cpu. Different contexts of a cpu will have different
meta-data, but all the contexts of a cpu will share the same cbuf.
If cbufs become embedded in cmsg, then we would allocate 1x cmsg
per-cpu. But the atomic consoles would still need their own 4x per-cpu
meta-data.
When looking at the proposal code, it looks wrong to have meta-data
fields in the cmsg struct that are not being used. But maybe that is
acceptable during the "transition phase" until all legacy consoles are
gone.
For v4 I will drop the console_buffers struct. I will use your
suggestion.
John
On 2023-01-02, Petr Mladek <[email protected]> wrote:
>> if (is_extended) {
>> len = info_print_ext_header(outbuf, outbuf_sz, r.info);
>> len += msg_print_ext_body(outbuf + len, outbuf_sz - len,
>> - &r.text_buf[0], r.info->text_len, &r.info->dev_info);
>> + r.text_buf, r.info->text_len, &r.info->dev_info);
>
> This probably was not intended.
Actually it was. But such a style change is not appropriate here. Sorry
for trying to slip it in.
John
On Tue 2023-01-03 16:03:17, John Ogness wrote:
> On 2023-01-03, Petr Mladek <[email protected]> wrote:
> > On Thu 2022-12-22 16:47:39, John Ogness wrote:
> >> On 2022-12-21, John Ogness <[email protected]> wrote:
> >> > +static bool console_emit_next_record(struct console *con, bool *handover, int cookie)
> >> > +{
> >> > + bool is_extended = console_srcu_read_flags(con) & CON_EXTENDED;
> >> > + static char dropped_text[DROPPED_TEXT_MAX];
> >> > + static struct console_buffers cbufs;
> >> > + static struct console_message cmsg = {
> >> > + .cbufs = &cbufs,
> >> > + };
> >>
> >> @cmsg should not be static. The whole point of the console_message
> >> wrapper struct is so that it can sit on the stack.
> >
> > Well, it might actually be better to keep it static for now.
> > It always points to static struct console_buffers cbufs anyway.
> >
> > It would make sense to have it on stack only when it uses
> > different buffers.
>
> I think we should avoid making things static when it serves no purpose.
I agree. Well, I still feel that both structures are tightly
connected and there should be 1:1 relation. See below.
> > Which brings the question. Does it makes sense to use
> > the same buffers by different struct console_message?
> > Will it be safe in any situation?
> >
> > I did not want to complicate it yesterday. I think that
> > I have already proposed this. But this brings back
> > the question whether it makes sense to have two structures
> > at all.
> >
> > I still think that it would be easier and even more safe
> > to put everything into struct console_message.
> >
> > I mean to have:
> >
> > struct console_message {
> > char buf[CONSOLE_EXT_LOG_MAX];
> > char scratch_buf[LOG_LINE_MAX];
> > unsigned int len;
> > u64 seq;
> > unsigned long dropped;
> > };
>
> The current atomic console proposal allocates 1x cbuf per-cpu and 4x
> meta-data per-cpu. Different contexts of a cpu will have different
> meta-data, but all the contexts of a cpu will share the same cbuf.
>
> If cbufs become embedded in cmsg, then we would allocate 1x cmsg
> per-cpu. But the atomic consoles would still need their own 4x per-cpu
> meta-data.
Do we really need 4x the meta data?
The metadata describe the state of the buffer. Using the buffer in one
context invalidates the metadata in the other context.
By other words, if one context reuses the buffer it might also
reuse the metadata. We just need to inform the original context
that it would need to break or re-start the operation. But we would
need to do this anyway.
This is my intuitive view. It is possible that I miss some
important detail.
> When looking at the proposal code, it looks wrong to have meta-data
> fields in the cmsg struct that are not being used. But maybe that is
> acceptable during the "transition phase" until all legacy consoles are
> gone.
I am not sure what you mean by "not being used".
When I try to find "struct console_buffers" with cscope
than I see it in:
+ struct console_message definition:
+ part of the structure
+ console_prepend_dropped()
+ console_get_next_message()
+ both read the pointer from the given struct message
+ console_emit_next_record()
+ static definition
+ the pointer is stored into struct console_message
In all situations, struct console_message is needed when
struct console_buffers is manipulated. By other words,
the metadata are always needed when the buffers are used.
> For v4 I will drop the console_buffers struct. I will use your
> suggestion.
Please, do not do it just to make me happy. My intention
is to keep things simple. And keeping the two structures
synced needs an extra code.
If you are sure that the separation will really be needed
in the future then feel free to keep the two structures.
Best Regards,
Petr
On Tue 2023-01-03 16:06:03, John Ogness wrote:
> On 2023-01-03, Petr Mladek <[email protected]> wrote:
> >> Actually, I would like to rename all of those limit macros to something
> >> that makes more sense for the new code base:
> >>
> >> CONSOLE_EXT_LOG_MAX -> CONSOLE_MESSAGE_MAX
> >>
> >> CONSOLE_LOG_MAX -> SYSLOG_MESSAGE_MAX
> >
> > Heh, we actually do not need this. The size of @scratchbuf
> > might be LOG_LINE_MAX/PRINTK_RECORD_MAX. The scratch buffer
> > is newly used only to read the plain message. The prefixes
> > are added to @outbuf.
> >
> >> LOG_LINE_MAX -> PRINTK_RECORD_MAX
>
> The scratch buffer would become PRINTK_RECORD_MAX, but we still need
> SYSLOG_MESSAGE_MAX for the kmalloc's syslog buffers.
I see.
> Unless you think it is OK to kmalloc 8KB instead of 1KB for the
> syslog calls. Then yes, we do not need SYSLOG_MESSAGE_MAX.
IMHO, it is acceptable and even correct. syslog uses the same
prefixes as console. It would make sense to use the same
buffers for formatting.
That said, 8kB looks non-necessary big to me.
It seems that it comes from devkmsg interface, see the commit
d43ff430f434d862db59582 ("printk: guard the amount written
per line by devkmsg_read()"). It was supposed to include
the message, the extended prefix and dictionary, where
+ message is limited by LOG_LINE_MAX
+ prefix includes few well defined fields (should be < 128B)
+ dictionary comes from dev_printk() => ( < 128B as well)
I believe that 2kB or 4kB would be perfectly fine.
Best Regards,
Petr
On 2023-01-03, Petr Mladek <[email protected]> wrote:
>> Unless you think it is OK to kmalloc 8KB instead of 1KB for the
>> syslog calls. Then yes, we do not need SYSLOG_MESSAGE_MAX.
>
> IMHO, it is acceptable and even correct. syslog uses the same
> prefixes as console. It would make sense to use the same
> buffers for formatting.
>
> That said, 8kB looks non-necessary big to me.
>
> It seems that it comes from devkmsg interface, see the commit
> d43ff430f434d862db59582 ("printk: guard the amount written
> per line by devkmsg_read()"). It was supposed to include
> the message, the extended prefix and dictionary, where
>
> + message is limited by LOG_LINE_MAX
> + prefix includes few well defined fields (should be < 128B)
> + dictionary comes from dev_printk() => ( < 128B as well)
>
> I believe that 2kB or 4kB would be perfectly fine.
The main issue is multi-line records. Normal messages become _much_
larger than extended messages in this case because they add a prefix per
'\n', whereas extended messages just use "\x0a". Extended messages
really could only end up being significantly longer than normal messages
if there are many non-printable characters in the message. But AFAIK
non-printables are not really used in printk messages.
So IMHO it does not make sense that normal messages are limited to 1KB
but extended messages can use 8KB. I agree that a universal limit of 2KB
for normal/extended/syslog would be a nice compromise. Normal messages
will have more space available and it will reduce the overall static
buffer usage. It would mean that syslog calls will kmalloc 2KB instead
of 1KB, but I expect that should be acceptable since, generally
speaking, overall we are reducing memory usage.
John
On Wed 2023-01-04 11:32:30, John Ogness wrote:
> On 2023-01-03, Petr Mladek <[email protected]> wrote:
> >> The current atomic console proposal allocates 1x cbuf per-cpu and 4x
> >> meta-data per-cpu. Different contexts of a cpu will have different
> >> meta-data, but all the contexts of a cpu will share the same cbuf.
> >>
> >> If cbufs become embedded in cmsg, then we would allocate 1x cmsg
> >> per-cpu. But the atomic consoles would still need their own 4x per-cpu
> >> meta-data.
> >
> > Do we really need 4x the meta data?
>
> Having per-context meta-data helps minimize data clobbering. For
> example, the message-formatting functions would not need to worry about
> @cmsg->len changing underneath them. This can be solved with a
> READ_ONCE() to a local variable and the function only using the local
> copy, but it will mean more copying of variables.
I see. I agree that a separate structure would avoid these problems.
> > The metadata describe the state of the buffer. Using the buffer in one
> > context invalidates the metadata in the other context.
>
> Yes, but the message-formatting functions are the ones preparing that
> meta-data. They must then be able to handle an interrupting context
> changing that meta-data.
>
> >> For v4 I will drop the console_buffers struct. I will use your
> >> suggestion.
> >
> > Please, do not do it just to make me happy. My intention
> > is to keep things simple. And keeping the two structures
> > synced needs an extra code.
> >
> > If you are sure that the separation will really be needed
> > in the future then feel free to keep the two structures.
>
> Currently the message-formatting functions do not care about clobbering
> of the text buffers. They blindly just move things around using the
> meta-data as safety boundaries. This can lead to a formatted-buffer that
> contains garbage, but an interrupted context will not print that buffer
> in the end. The important thing is that the garbage was created safely.
Right.
> Avoiding a separate console_buffers structure may simplify the
> structures, but it requires robustifying the message-formatting
> functions to be tolerant for meta-data clobbering.
>
> I am currently implementing such changes to see if it is feasible.
Please, do not spend too much time on this.
I think that the two structures make sense in the end. Just please
mention the metadata clobbering as the motivation in the commit
message.
Best Regards,
Petr
On Wed 2023-01-04 10:12:01, John Ogness wrote:
> On 2023-01-03, Petr Mladek <[email protected]> wrote:
> >> Unless you think it is OK to kmalloc 8KB instead of 1KB for the
> >> syslog calls. Then yes, we do not need SYSLOG_MESSAGE_MAX.
> >
> > IMHO, it is acceptable and even correct. syslog uses the same
> > prefixes as console. It would make sense to use the same
> > buffers for formatting.
> >
> > That said, 8kB looks non-necessary big to me.
> >
> > It seems that it comes from devkmsg interface, see the commit
> > d43ff430f434d862db59582 ("printk: guard the amount written
> > per line by devkmsg_read()"). It was supposed to include
> > the message, the extended prefix and dictionary, where
> >
> > + message is limited by LOG_LINE_MAX
> > + prefix includes few well defined fields (should be < 128B)
> > + dictionary comes from dev_printk() => ( < 128B as well)
> >
> > I believe that 2kB or 4kB would be perfectly fine.
>
> The main issue is multi-line records. Normal messages become _much_
> larger than extended messages in this case because they add a prefix per
> '\n', whereas extended messages just use "\x0a". Extended messages
> really could only end up being significantly longer than normal messages
> if there are many non-printable characters in the message. But AFAIK
> non-printables are not really used in printk messages.
Right.
> So IMHO it does not make sense that normal messages are limited to 1KB
> but extended messages can use 8KB. I agree that a universal limit of 2KB
> for normal/extended/syslog would be a nice compromise. Normal messages
> will have more space available and it will reduce the overall static
> buffer usage. It would mean that syslog calls will kmalloc 2KB instead
> of 1KB, but I expect that should be acceptable since, generally
> speaking, overall we are reducing memory usage.
I agree that 2kB are a good compromise and the allocation should be acceptable.
Best Regards,
Petr
On 2023-01-03, Petr Mladek <[email protected]> wrote:
>> The current atomic console proposal allocates 1x cbuf per-cpu and 4x
>> meta-data per-cpu. Different contexts of a cpu will have different
>> meta-data, but all the contexts of a cpu will share the same cbuf.
>>
>> If cbufs become embedded in cmsg, then we would allocate 1x cmsg
>> per-cpu. But the atomic consoles would still need their own 4x per-cpu
>> meta-data.
>
> Do we really need 4x the meta data?
Having per-context meta-data helps minimize data clobbering. For
example, the message-formatting functions would not need to worry about
@cmsg->len changing underneath them. This can be solved with a
READ_ONCE() to a local variable and the function only using the local
copy, but it will mean more copying of variables.
> The metadata describe the state of the buffer. Using the buffer in one
> context invalidates the metadata in the other context.
Yes, but the message-formatting functions are the ones preparing that
meta-data. They must then be able to handle an interrupting context
changing that meta-data.
>> For v4 I will drop the console_buffers struct. I will use your
>> suggestion.
>
> Please, do not do it just to make me happy. My intention
> is to keep things simple. And keeping the two structures
> synced needs an extra code.
>
> If you are sure that the separation will really be needed
> in the future then feel free to keep the two structures.
Currently the message-formatting functions do not care about clobbering
of the text buffers. They blindly just move things around using the
meta-data as safety boundaries. This can lead to a formatted-buffer that
contains garbage, but an interrupted context will not print that buffer
in the end. The important thing is that the garbage was created safely.
Avoiding a separate console_buffers structure may simplify the
structures, but it requires robustifying the message-formatting
functions to be tolerant for meta-data clobbering.
I am currently implementing such changes to see if it is feasible.
John
Hi John,
I love your patch! Perhaps something to improve:
[auto build test WARNING on 6b2b0d839acaa84f05a77184370f793752e786e9]
url: https://github.com/intel-lab-lkp/linux/commits/John-Ogness/printk-cleanup-buffer-handling/20221222-044216
base: 6b2b0d839acaa84f05a77184370f793752e786e9
patch link: https://lore.kernel.org/r/20221221202704.857925-7-john.ogness%40linutronix.de
patch subject: [PATCH printk v3 6/6] printk: introduce console_prepend_dropped() for dropped messages
config: loongarch-randconfig-m031-20230103
compiler: loongarch64-linux-gcc (GCC) 12.1.0
If you fix the issue, kindly add following tag where applicable
| Reported-by: kernel test robot <[email protected]>
smatch warnings:
kernel/printk/printk.c:2735 console_prepend_dropped() warn: always true condition '(cmsg->outbuf_len + len >= outbuf_sz) => (0-u64max >= 0)'
vim +2735 kernel/printk/printk.c
2701
2702 /*
2703 * Prepend the message in @cmsg->cbufs->outbuf with a "dropped message". This
2704 * is achieved by shifting the existing message over and inserting the dropped
2705 * message.
2706 *
2707 * @cmsg is the console message to prepend.
2708 *
2709 * @dropped is the dropped count to report in the dropped message.
2710 *
2711 * If the message text in @cmsg->cbufs->outbuf does not have enough space for
2712 * the dropped message, the message text will be sufficiently truncated.
2713 *
2714 * If @cmsg->cbufs->outbuf is modified, @cmsg->outbuf_len is updated.
2715 */
2716 static void console_prepend_dropped(struct console_message *cmsg, unsigned long dropped)
2717 {
2718 struct console_buffers *cbufs = cmsg->cbufs;
2719 const size_t scratchbuf_sz = sizeof(cbufs->scratchbuf);
2720 const size_t outbuf_sz = sizeof(cbufs->outbuf);
2721 char *scratchbuf = &cbufs->scratchbuf[0];
2722 char *outbuf = &cbufs->outbuf[0];
2723 size_t len;
2724
2725 len = snprintf(scratchbuf, scratchbuf_sz,
2726 "** %lu printk messages dropped **\n", dropped);
2727
2728 /*
2729 * Make sure outbuf is sufficiently large before prepending. Space
2730 * for a terminator is also counted in case truncation occurs.
2731 */
2732 if (WARN_ON_ONCE(len + 1 >= outbuf_sz))
2733 return;
2734
> 2735 if (cmsg->outbuf_len + len >= outbuf_sz) {
2736 /* Truncate the message, but keep it terminated. */
2737 cmsg->outbuf_len = outbuf_sz - (len + 1);
2738 outbuf[cmsg->outbuf_len] = 0;
2739 }
2740
2741 memmove(outbuf + len, outbuf, cmsg->outbuf_len + 1);
2742 memcpy(outbuf, scratchbuf, len);
2743 cmsg->outbuf_len += len;
2744 }
2745
--
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests
On 2023-01-05, kernel test robot <[email protected]> wrote:
> smatch warnings:
> kernel/printk/printk.c:2735 console_prepend_dropped() warn: always true condition '(cmsg->outbuf_len + len >= outbuf_sz) => (0-u64max >= 0)'
Thank you kernel test robot, but actually this code will never be hit
when outbuf_sz is 0. Explanation below.
> vim +2735 kernel/printk/printk.c
>
> 2701
> 2702 /*
> 2703 * Prepend the message in @cmsg->cbufs->outbuf with a "dropped message". This
> 2704 * is achieved by shifting the existing message over and inserting the dropped
> 2705 * message.
> 2706 *
> 2707 * @cmsg is the console message to prepend.
> 2708 *
> 2709 * @dropped is the dropped count to report in the dropped message.
> 2710 *
> 2711 * If the message text in @cmsg->cbufs->outbuf does not have enough space for
> 2712 * the dropped message, the message text will be sufficiently truncated.
> 2713 *
> 2714 * If @cmsg->cbufs->outbuf is modified, @cmsg->outbuf_len is updated.
> 2715 */
> 2716 static void console_prepend_dropped(struct console_message *cmsg, unsigned long dropped)
> 2717 {
> 2718 struct console_buffers *cbufs = cmsg->cbufs;
> 2719 const size_t scratchbuf_sz = sizeof(cbufs->scratchbuf);
> 2720 const size_t outbuf_sz = sizeof(cbufs->outbuf);
> 2721 char *scratchbuf = &cbufs->scratchbuf[0];
> 2722 char *outbuf = &cbufs->outbuf[0];
> 2723 size_t len;
> 2724
> 2725 len = snprintf(scratchbuf, scratchbuf_sz,
> 2726 "** %lu printk messages dropped **\n", dropped);
> 2727
> 2728 /*
> 2729 * Make sure outbuf is sufficiently large before prepending. Space
> 2730 * for a terminator is also counted in case truncation occurs.
> 2731 */
> 2732 if (WARN_ON_ONCE(len + 1 >= outbuf_sz))
> 2733 return;
If outbuf_sz is 0, the above check will return. It is interesting that
smatch did not complain about this line instead. I suppose the
WARN_ON_ONCE confused it.
Note that if outbuf_sz is 0, then CONFIG_PRINTK is undefined. In that
case this function should not be called anyway. So the check and warning
are appropriate here.
> 2734
>> 2735 if (cmsg->outbuf_len + len >= outbuf_sz) {
John Ogness