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/[email protected]
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
From: Thomas Gleixner <[email protected]>
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 <[email protected]>
Signed-off-by: John Ogness <[email protected]>
---
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
From: Thomas Gleixner <[email protected]>
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 <[email protected]>
Signed-off-by: John Ogness <[email protected]>
---
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
From: Thomas Gleixner <[email protected]>
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 <[email protected]>
Signed-off-by: John Ogness <[email protected]>
---
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
From: Thomas Gleixner <[email protected]>
Add kerneldoc comments to struct console.
Signed-off-by: Thomas Gleixner <[email protected]>
Signed-off-by: John Ogness <[email protected]>
---
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
From: Thomas Gleixner <[email protected]>
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 <[email protected]>
Signed-off-by: John Ogness <[email protected]>
---
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
On Thu 2022-11-24 00:19:55, John Ogness wrote:
> From: Thomas Gleixner <[email protected]>
>
> 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 <[email protected]>
> Signed-off-by: John Ogness <[email protected]>
This is really useful.
Reviewed-by: Petr Mladek <[email protected]>
Best Regards,
Petr
On Thu 2022-11-24 00:19:56, John Ogness wrote:
> From: Thomas Gleixner <[email protected]>
>
> Add kerneldoc comments to struct console.
>
> Signed-off-by: Thomas Gleixner <[email protected]>
> Signed-off-by: John Ogness <[email protected]>
Nice improvement.
Reviewed-by: Petr Mladek <[email protected]>
Best Regards,
Petr
On Thu 2022-11-24 00:19:58, John Ogness wrote:
> From: Thomas Gleixner <[email protected]>
>
> 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
On Thu 2022-11-24 00:19:59, John Ogness wrote:
> From: Thomas Gleixner <[email protected]>
>
> 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.
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
On 2022-11-24, Petr Mladek <[email protected]> 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
On 2022-11-24, Petr Mladek <[email protected]> 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
On Thu 2022-11-24 22:21:08, John Ogness wrote:
> On 2022-11-24, Petr Mladek <[email protected]> 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
On 2022-11-25, Petr Mladek <[email protected]> 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
On Fri 2022-11-25 11:55:28, John Ogness wrote:
> On 2022-11-25, Petr Mladek <[email protected]> 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
On Thu 2022-11-24 00:20:00, John Ogness wrote:
> From: Thomas Gleixner <[email protected]>
>
> 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
On 2022-12-07, Petr Mladek <[email protected]> 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
On Wed 2022-12-07 18:04:56, John Ogness wrote:
> On 2022-12-07, Petr Mladek <[email protected]> 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