Messages in this thread Patch in this message | | | From | Petr Mladek <> | Subject | [PATCH POC 2/4] printk: Do not block cont buffer by partially flushed lines | Date | Fri, 15 Jul 2016 18:59:00 +0200 |
| |
Parts of the line can be preliminary flushed to the console by console_cont_flush(). When this happen, the cont buffer could not be used for new lines until the rest of the original line is flushed. This might cause unnecessary fragmentation of continuous lines.
But there is always only one partially flushed line. We do not need any per line LOG_NOCONS flag. Instead, we could simply remember the related sequence number.
Also we could construct a fake cont structure from the information stored in the ring buffer.
Therefore, we could always flush the log buffer and make the whole logic easier.
Finally, it makes perfect sense to use the time stamp of the first continuous fragment. This is why cont_flush() can be so trivial now.
Signed-off-by: Petr Mladek <pmladek@suse.com> --- kernel/printk/printk.c | 123 ++++++++++++++++++++----------------------------- 1 file changed, 49 insertions(+), 74 deletions(-)
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c index 71e96aae98e7..7d93ac263006 100644 --- a/kernel/printk/printk.c +++ b/kernel/printk/printk.c @@ -222,7 +222,6 @@ static int console_may_schedule; */ enum log_flags { - LOG_NOCONS = 1, /* already flushed, do not print to console */ LOG_NEWLINE = 2, /* text ended with a newline */ LOG_PREFIX = 4, /* text started with a prefix */ LOG_CONT = 8, /* text is a fragment of a continuation line */ @@ -1522,11 +1521,12 @@ struct cont { struct task_struct *owner; /* task of first print*/ struct printk_log *msg; /* more info about the stored text */ char *buf; /* buffer to the stored text */ - bool flushed:1; /* buffer sealed and committed */ }; /* bytes written to console */ static size_t cont_console_len; +/* sequence number related to the partially flushed line */ +static u64 cont_console_seq; static struct printk_log cont_msg; static char cont_buf[LOG_LINE_MAX]; @@ -1538,38 +1538,16 @@ static struct cont cont = { static void cont_flush(enum log_flags flags) { - if (cont.flushed) - return; if (cont.msg->text_len == 0) return; - if (cont_console_len) { - /* - * If a fragment of this line was directly flushed to the - * console; wait for the console to pick up the rest of the - * line. LOG_NOCONS suppresses a duplicated output. - */ - log_store(cont.msg->facility, cont.msg->level, - flags | LOG_NOCONS, cont.msg->ts_nsec, - NULL, 0, cont.buf, cont.msg->text_len); - cont.msg->flags = flags; - cont.flushed = true; - } else { - /* - * If no fragment of this line ever reached the console, - * just submit it to the store and free the buffer. - */ - log_store(cont.msg->facility, cont.msg->level, flags, 0, - NULL, 0, cont.buf, cont.msg->text_len); - cont.msg->text_len = 0; - } + log_store(cont.msg->facility, cont.msg->level, flags, + cont.msg->ts_nsec, NULL, 0, cont.buf, cont.msg->text_len); + cont.msg->text_len = 0; } static bool cont_add(int facility, int level, const char *text, size_t len) { - if (cont.msg->text_len && cont.flushed) - return false; - /* * If ext consoles are present, flush and skip in-kernel * continuation. See nr_ext_console_drivers definition. Also, if @@ -1587,8 +1565,6 @@ static bool cont_add(int facility, int level, const char *text, size_t len) cont.msg->level = level; cont.msg->ts_nsec = local_clock(); cont.msg->flags = 0; - cont.flushed = false; - cont_console_len = 0; } memcpy(cont.buf + cont.msg->text_len, text, len); @@ -1600,31 +1576,29 @@ static bool cont_add(int facility, int level, const char *text, size_t len) return true; } -static size_t cont_print_text(char *text, size_t size) +static size_t cont_print_text(struct cont *cont, char *text, size_t size) { size_t textlen = 0; size_t len; if (cont_console_len == 0 && (console_prev & LOG_NEWLINE)) { - textlen += print_time(cont.msg->ts_nsec, text); + textlen += print_time(cont->msg->ts_nsec, text); size -= textlen; } - len = cont.msg->text_len - cont_console_len; + len = cont->msg->text_len - cont_console_len; if (len > 0) { if (len+1 > size) len = size-1; - memcpy(text + textlen, cont.buf + cont_console_len, len); + memcpy(text + textlen, cont->buf + cont_console_len, len); textlen += len; - cont_console_len = cont.msg->text_len; + cont_console_len = cont->msg->text_len; + cont_console_seq = console_seq; } - if (cont.flushed) { - if (cont.msg->flags & LOG_NEWLINE) - text[textlen++] = '\n'; - /* got everything, release buffer */ - cont.msg->text_len = 0; - } + if (cont->msg->flags & LOG_NEWLINE) + text[textlen++] = '\n'; + return textlen; } @@ -1917,7 +1891,6 @@ static struct cont { size_t len; size_t cons; u8 level; - bool flushed:1; } cont; static char *log_text(const struct printk_log *msg) { return NULL; } static char *log_dict(const struct printk_log *msg) { return NULL; } @@ -2215,14 +2188,13 @@ static void console_cont_flush(char *text, size_t size) goto out; /* - * We still queue earlier records, likely because the console was - * busy. The earlier ones need to be printed before this one, we - * did not flush any fragment so far, so just let it queue up. + * If the partially printed line is already stored in + * the ring buffer, it will be handled with the other lines. */ - if (console_seq < log_next_seq && !cont_console_len) + if (console_seq < log_next_seq) goto out; - len = cont_print_text(text, size); + len = cont_print_text(&cont, text, size); raw_spin_unlock(&logbuf_lock); stop_critical_timings(); call_console_drivers(cont.msg->level, NULL, 0, text, len); @@ -2312,40 +2284,43 @@ again: } else { len = 0; } -skip: + if (console_seq == log_next_seq) break; msg = log_from_idx(console_idx); - if (msg->flags & LOG_NOCONS) { - /* - * Skip record we have buffered and already printed - * directly to the console when we received it. - */ - console_idx = log_next(console_idx); - console_seq++; - /* - * We will get here again when we register a new - * CON_PRINTBUFFER console. Clear the flag so we - * will properly dump everything later. - */ - msg->flags &= ~LOG_NOCONS; - console_prev = msg->flags; - goto skip; - } - level = msg->level; - len += msg_print_text(msg, console_prev, false, - text + len, sizeof(text) - len); - if (nr_ext_console_drivers) { - ext_len = msg_print_ext_header(ext_text, - sizeof(ext_text), - msg, console_seq, console_prev); - ext_len += msg_print_ext_body(ext_text + ext_len, - sizeof(ext_text) - ext_len, - log_dict(msg), msg->dict_len, - log_text(msg), msg->text_len); + + /* + * The line might be already partially printed from the cont + * buffer. In this case, flush the rest using a fake + * cont buffer. + */ + if (cont_console_len && cont_console_seq == console_seq) { + struct cont fake_cont; + + fake_cont.owner = NULL; + fake_cont.msg = msg; + fake_cont.buf = log_text(msg); + + len += cont_print_text(&fake_cont, text + len, sizeof(text) - len); + + cont_console_len = 0; + cont_console_seq = 0; + } else { + len += msg_print_text(msg, console_prev, false, + text + len, sizeof(text) - len); + if (nr_ext_console_drivers) { + ext_len = msg_print_ext_header(ext_text, + sizeof(ext_text), + msg, console_seq, console_prev); + ext_len += msg_print_ext_body(ext_text + ext_len, + sizeof(ext_text) - ext_len, + log_dict(msg), msg->dict_len, + log_text(msg), msg->text_len); + } } + console_idx = log_next(console_idx); console_seq++; console_prev = msg->flags; -- 1.8.5.6
| |