Linux kernel mirror (for testing) git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
kernel os linux

printk: remove console flushing special cases for partial buffered lines

It actively hurts proper merging, and makes for a lot of special cases.
There was a good(ish) reason for doing it originally, but it's getting
too painful to maintain. And most of the original reasons for it are
long gone.

So instead of having special code to flush partial lines to the console
(as opposed to the record buffers), do _all_ the console writing from
the record buffer, and be done with it.

If an oops happens (or some other synchronous event), we will flush the
partial lines due to the oops printing activity, so this does not affect
that. It does mean that if you have a completely hung machine, a
partial preceding line may not have been printed out.

That was some of the original reason for this complexity, in fact, back
when we used to test for the historical i386 "halt" instruction problem
by doing

pr_info("Checking 'hlt' instruction... ");

if (!boot_cpu_data.hlt_works_ok) {
pr_cont("disabled\n");
return;
}
halt();
halt();
halt();
halt();
pr_cont("OK\n");

and that model no longer works (it the 'hlt' instruction kills the
machine, the partial line won't have been flushed, so you won't even see
it).

Of course, that was also back in the days when people actually had
textual console output rather than a graphical splash-screen at bootup.
How times change..

Cc: Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com>
Cc: Joe Perches <joe@perches.com>
Cc: Steven Rostedt <rostedt@goodmis.org>
Tested-by: Petr Mladek <pmladek@suse.com>
Tested-by: Geert Uytterhoeven <geert@linux-m68k.org>
Tested-by: Mark Rutland <mark.rutland@arm.com>
Signed-off-by: Linus Torvalds <torvalds@linux-foundation.org>

+5 -103
+5 -103
kernel/printk/printk.c
··· 1583 1583 static struct cont { 1584 1584 char buf[LOG_LINE_MAX]; 1585 1585 size_t len; /* length == 0 means unused buffer */ 1586 - size_t cons; /* bytes written to console */ 1587 1586 struct task_struct *owner; /* task of first print*/ 1588 1587 u64 ts_nsec; /* time of first print */ 1589 1588 u8 level; /* log level of first message */ 1590 1589 u8 facility; /* log facility of first message */ 1591 1590 enum log_flags flags; /* prefix, newline flags */ 1592 - bool flushed:1; /* buffer sealed and committed */ 1593 1591 } cont; 1594 1592 1595 1593 static void cont_flush(void) 1596 1594 { 1597 - if (cont.flushed) 1598 - return; 1599 1595 if (cont.len == 0) 1600 1596 return; 1601 - if (cont.cons) { 1602 - /* 1603 - * If a fragment of this line was directly flushed to the 1604 - * console; wait for the console to pick up the rest of the 1605 - * line. LOG_NOCONS suppresses a duplicated output. 1606 - */ 1607 - log_store(cont.facility, cont.level, cont.flags | LOG_NOCONS, 1608 - cont.ts_nsec, NULL, 0, cont.buf, cont.len); 1609 - cont.flushed = true; 1610 - } else { 1611 - /* 1612 - * If no fragment of this line ever reached the console, 1613 - * just submit it to the store and free the buffer. 1614 - */ 1615 - log_store(cont.facility, cont.level, cont.flags, 0, 1616 - NULL, 0, cont.buf, cont.len); 1617 - cont.len = 0; 1618 - } 1597 + 1598 + log_store(cont.facility, cont.level, cont.flags, cont.ts_nsec, 1599 + NULL, 0, cont.buf, cont.len); 1600 + cont.len = 0; 1619 1601 } 1620 1602 1621 1603 static bool cont_add(int facility, int level, enum log_flags flags, const char *text, size_t len) 1622 1604 { 1623 - if (cont.len && cont.flushed) 1624 - return false; 1625 - 1626 1605 /* 1627 1606 * If ext consoles are present, flush and skip in-kernel 1628 1607 * continuation. See nr_ext_console_drivers definition. Also, if ··· 1618 1639 cont.owner = current; 1619 1640 cont.ts_nsec = local_clock(); 1620 1641 cont.flags = flags; 1621 - cont.cons = 0; 1622 - cont.flushed = false; 1623 1642 } 1624 1643 1625 1644 memcpy(cont.buf + cont.len, text, len); ··· 1634 1657 cont_flush(); 1635 1658 1636 1659 return true; 1637 - } 1638 - 1639 - static size_t cont_print_text(char *text, size_t size) 1640 - { 1641 - size_t textlen = 0; 1642 - size_t len; 1643 - 1644 - if (cont.cons == 0) { 1645 - textlen += print_time(cont.ts_nsec, text); 1646 - size -= textlen; 1647 - } 1648 - 1649 - len = cont.len - cont.cons; 1650 - if (len > 0) { 1651 - if (len+1 > size) 1652 - len = size-1; 1653 - memcpy(text + textlen, cont.buf + cont.cons, len); 1654 - textlen += len; 1655 - cont.cons = cont.len; 1656 - } 1657 - 1658 - if (cont.flushed) { 1659 - if (cont.flags & LOG_NEWLINE) 1660 - text[textlen++] = '\n'; 1661 - /* got everything, release buffer */ 1662 - cont.len = 0; 1663 - } 1664 - return textlen; 1665 1660 } 1666 1661 1667 1662 static size_t log_output(int facility, int level, enum log_flags lflags, const char *dict, size_t dictlen, char *text, size_t text_len) ··· 1906 1957 const char *text, size_t len) {} 1907 1958 static size_t msg_print_text(const struct printk_log *msg, 1908 1959 bool syslog, char *buf, size_t size) { return 0; } 1909 - static size_t cont_print_text(char *text, size_t size) { return 0; } 1910 1960 static bool suppress_message_printing(int level) { return false; } 1911 1961 1912 1962 /* Still needs to be defined for users */ ··· 2169 2221 return cpu_online(raw_smp_processor_id()) || have_callable_console(); 2170 2222 } 2171 2223 2172 - static void console_cont_flush(char *text, size_t size) 2173 - { 2174 - unsigned long flags; 2175 - size_t len; 2176 - 2177 - raw_spin_lock_irqsave(&logbuf_lock, flags); 2178 - 2179 - if (!cont.len) 2180 - goto out; 2181 - 2182 - if (suppress_message_printing(cont.level)) { 2183 - cont.cons = cont.len; 2184 - if (cont.flushed) 2185 - cont.len = 0; 2186 - goto out; 2187 - } 2188 - 2189 - /* 2190 - * We still queue earlier records, likely because the console was 2191 - * busy. The earlier ones need to be printed before this one, we 2192 - * did not flush any fragment so far, so just let it queue up. 2193 - */ 2194 - if (console_seq < log_next_seq && !cont.cons) 2195 - goto out; 2196 - 2197 - len = cont_print_text(text, size); 2198 - raw_spin_unlock(&logbuf_lock); 2199 - stop_critical_timings(); 2200 - call_console_drivers(cont.level, NULL, 0, text, len); 2201 - start_critical_timings(); 2202 - local_irq_restore(flags); 2203 - return; 2204 - out: 2205 - raw_spin_unlock_irqrestore(&logbuf_lock, flags); 2206 - } 2207 - 2208 2224 /** 2209 2225 * console_unlock - unlock the console system 2210 2226 * ··· 2222 2310 return; 2223 2311 } 2224 2312 2225 - /* flush buffered message fragment immediately to console */ 2226 - console_cont_flush(text, sizeof(text)); 2227 - 2228 2313 for (;;) { 2229 2314 struct printk_log *msg; 2230 2315 size_t ext_len = 0; ··· 2250 2341 2251 2342 msg = log_from_idx(console_idx); 2252 2343 level = msg->level; 2253 - if ((msg->flags & LOG_NOCONS) || 2254 - suppress_message_printing(level)) { 2344 + if (suppress_message_printing(level)) { 2255 2345 /* 2256 2346 * Skip record we have buffered and already printed 2257 2347 * directly to the console when we received it, and ··· 2258 2350 */ 2259 2351 console_idx = log_next(console_idx); 2260 2352 console_seq++; 2261 - /* 2262 - * We will get here again when we register a new 2263 - * CON_PRINTBUFFER console. Clear the flag so we 2264 - * will properly dump everything later. 2265 - */ 2266 - msg->flags &= ~LOG_NOCONS; 2267 2353 goto skip; 2268 2354 } 2269 2355