iv/linux
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

printk: introduce printk_get_next_message() and printk_message

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

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

Why is struct printk_message a wrapper struct?

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

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

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

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

Signed-off-by: John Ogness <john.ogness@linutronix.de>
Reviewed-by: Petr Mladek <pmladek@suse.com>
Signed-off-by: Petr Mladek <pmladek@suse.com>
Link: https://lore.kernel.org/r/20230109100800.1085541-6-john.ogness@linutronix.de
This commit is contained in:
John Ogness 2023-01-09 11:13:57 +01:06 committed by Petr Mladek
parent daaab5b5bb
commit 2830eec14a
2 changed files with 102 additions and 41 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

16
kernel/printk/internal.h
View File

@ -92,3 +92,19 @@ struct printk_buffers {
char outbuf[CONSOLE_EXT_LOG_MAX];
char scratchbuf[LOG_LINE_MAX];
};
/**
* struct printk_message - Container for a prepared printk message.
* @pbufs: printk buffers used to prepare the message.
* @outbuf_len: The length of prepared text in @pbufs->outbuf to output. This
* does not count the terminator. A value of 0 means there is
* nothing to output and this record should be skipped.
* @seq: The sequence number of the record used for @pbufs->outbuf.
* @dropped: The number of dropped records from reading @seq.
*/
struct printk_message {
struct printk_buffers *pbufs;
unsigned int outbuf_len;
u64 seq;
unsigned long dropped;
};

127
kernel/printk/printk.c
View File

@ -2724,6 +2724,82 @@ static void __console_unlock(void)
up_console_sem();
}
/*
* Read and format the specified record (or a later record if the specified
* record is not available).
*
* @pmsg will contain the formatted result. @pmsg->pbufs must point to a
* struct printk_buffers.
*
* @seq is the record to read and format. If it is not available, the next
* valid record is read.
*
* @is_extended specifies if the message should be formatted for extended
* console output.
*
* Returns false if no record is available. Otherwise true and all fields
* of @pmsg are valid. (See the documentation of struct printk_message
* for information about the @pmsg fields.)
*/
static bool printk_get_next_message(struct printk_message *pmsg, u64 seq,
bool is_extended)
{
static int panic_console_dropped;
struct printk_buffers *pbufs = pmsg->pbufs;
const size_t scratchbuf_sz = sizeof(pbufs->scratchbuf);
const size_t outbuf_sz = sizeof(pbufs->outbuf);
char *scratchbuf = &pbufs->scratchbuf[0];
char *outbuf = &pbufs->outbuf[0];
struct printk_info info;
struct printk_record r;
size_t len = 0;
/*
* Formatting extended messages requires a separate buffer, so use the
* scratch buffer to read in the ringbuffer text.
*
* Formatting normal messages is done in-place, so read the ringbuffer
* text directly into the output buffer.
*/
if (is_extended)
prb_rec_init_rd(&r, &info, scratchbuf, scratchbuf_sz);
else
prb_rec_init_rd(&r, &info, outbuf, outbuf_sz);
if (!prb_read_valid(prb, seq, &r))
return false;
pmsg->seq = r.info->seq;
pmsg->dropped = r.info->seq - seq;
/*
* Check for dropped messages in panic here so that printk
* suppression can occur as early as possible if necessary.
*/
if (pmsg->dropped &&
panic_in_progress() &&
panic_console_dropped++ > 10) {
suppress_panic_printk = 1;
pr_warn_once("Too many dropped messages. Suppress messages on non-panic CPUs to prevent livelock.\n");
}
/* Skip record that has level above the console loglevel. */
if (suppress_message_printing(r.info->level))
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);
} else {
len = record_print_text(&r, console_msg_format & MSG_FORMAT_SYSLOG, printk_time);
}
out:
pmsg->outbuf_len = len;
return true;
}
/*
* Print one record for the given console. The record printed is whatever
* record is the next available record for the given console.
@ -2743,58 +2819,27 @@ static bool console_emit_next_record(struct console *con, bool *handover, int co
{
static char dropped_text[DROPPED_TEXT_MAX];
static struct printk_buffers pbufs;
static int panic_console_dropped;
bool is_extended = console_srcu_read_flags(con) & CON_EXTENDED;
const size_t scratchbuf_sz = sizeof(pbufs.scratchbuf);
const size_t outbuf_sz = sizeof(pbufs.outbuf);
char *scratchbuf = &pbufs.scratchbuf[0];
char *outbuf = &pbufs.outbuf[0];
struct printk_info info;
struct printk_record r;
struct printk_message pmsg = {
.pbufs = &pbufs,
};
unsigned long flags;
size_t len;
/*
* Formatting extended messages requires a separate buffer, so use the
* scratch buffer to read in the ringbuffer text.
*
* Formatting normal messages is done in-place, so read the ringbuffer
* text directly into the output buffer.
*/
if (is_extended)
prb_rec_init_rd(&r, &info, scratchbuf, scratchbuf_sz);
else
prb_rec_init_rd(&r, &info, outbuf, outbuf_sz);
*handover = false;
if (!prb_read_valid(prb, con->seq, &r))
if (!printk_get_next_message(&pmsg, con->seq, is_extended))
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");
}
}
con->dropped += pmsg.dropped;
/* Skip record that has level above the console loglevel. */
if (suppress_message_printing(r.info->level)) {
con->seq++;
/* Skip messages of formatted length 0. */
if (pmsg.outbuf_len == 0) {
con->seq = pmsg.seq + 1;
goto skip;
}
if (is_extended) {
len = info_print_ext_header(outbuf, outbuf_sz, r.info);
len += msg_print_ext_body(outbuf + len, outbuf_sz - len,
&r.text_buf[0], r.info->text_len, &r.info->dev_info);
} else {
len = record_print_text(&r, console_msg_format & MSG_FORMAT_SYSLOG, printk_time);
}
/*
* While actively printing out messages, if another printk()
* were to occur on another CPU, it may wait for this one to
@ -2809,11 +2854,11 @@ static bool console_emit_next_record(struct console *con, bool *handover, int co
console_lock_spinning_enable();
stop_critical_timings(); /* don't trace print latency */
call_console_driver(con, outbuf, len,
call_console_driver(con, outbuf, pmsg.outbuf_len,
is_extended ? NULL : dropped_text);
start_critical_timings();
con->seq++;
con->seq = pmsg.seq + 1;
*handover = console_lock_spinning_disable_and_check(cookie);
printk_safe_exit_irqrestore(flags);