[PATCH 1/3] printk: Introduce buffered_printk().

From: Tetsuo Handa
Date: Wed Jun 27 2018 - 03:29:14 EST


Linus suggested in "printk: what is going on with additional newlines?"
thread [1] that

Making the buffer explicit is (a) cheaper and (b) better. Now you can
put the buffer on the stack, you never have to worry about where you
need to track context, and you have no buffering limits (ie you can
buffer across any event).

I definitely suspect that "single line" is often sufficient. I
mean, that's all that KERN_CONT ever gave you anyway (and not reliably).

And then a 80 character buffer really isn't any different from having
a structure with a few pointers in it, which we do on the stack all
the time.

Now, since syzbot is bothered by concurrent printk() messages (e.g.
memory allocation fault injection), we started thinking about adding
prefix to each line of printk() output. This matches the suggestion that
buffering single line will be sufficient if we add caller's context
information for distinguishing concurrent printk() messages.

Thus, this patch introduces buffered_printk() which spools printk() output
and automatically flushes when '\n' was found or buffer became full (and
related structure/macro/functions).

[1] http://lkml.kernel.org/r/CA+55aFx+5R-vFQfr7+Ok9Yrs2adQ2Ma4fz+S6nCyWHY_-2mrmw@xxxxxxxxxxxxxx

Signed-off-by: Tetsuo Handa <penguin-kernel@xxxxxxxxxxxxxxxxxxx>
---
include/linux/printk.h | 28 ++++++++++++++++
kernel/printk/printk.c | 86 ++++++++++++++++++++++++++++++++++++++++++++++++++
2 files changed, 114 insertions(+)

diff --git a/include/linux/printk.h b/include/linux/printk.h
index 6d7e800..81bc12a 100644
--- a/include/linux/printk.h
+++ b/include/linux/printk.h
@@ -153,6 +153,23 @@ static inline void printk_nmi_enter(void) { }
static inline void printk_nmi_exit(void) { }
#endif /* PRINTK_NMI */

+struct printk_buffer {
+ unsigned short int size;
+ unsigned short int used;
+ char *buf;
+};
+
+#define DEFINE_PRINTK_BUFFER(name, size, buf) \
+ struct printk_buffer name = { size, 0, buf }
+
+static inline void INIT_PRINTK_BUFFER(struct printk_buffer *ptr,
+ unsigned short int size, char *buf)
+{
+ ptr->size = size;
+ ptr->used = 0;
+ ptr->buf = buf;
+}
+
#ifdef CONFIG_PRINTK
asmlinkage __printf(5, 0)
int vprintk_emit(int facility, int level,
@@ -169,6 +186,9 @@ int printk_emit(int facility, int level,

asmlinkage __printf(1, 2) __cold
int printk(const char *fmt, ...);
+asmlinkage __printf(2, 3) __cold
+int buffered_printk(struct printk_buffer *ptr, const char *fmt, ...);
+void flush_buffered_printk(struct printk_buffer *ptr);

/*
* Special printk facility for scheduler/timekeeping use only, _DO_NOT_USE_ !
@@ -216,6 +236,14 @@ int printk(const char *s, ...)
{
return 0;
}
+static inline __printf(2, 3) __cold
+int buffered_printk(struct printk_buffer *ptr, const char *fmt, ...)
+{
+ return 0;
+}
+static inline void flush_buffered_printk(struct printk_buffer *ptr)
+{
+}
static inline __printf(1, 2) __cold
int printk_deferred(const char *s, ...)
{
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 2478083..24566dc 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1985,6 +1985,92 @@ asmlinkage __visible int printk(const char *fmt, ...)
}
EXPORT_SYMBOL(printk);

+static void __flush_printk_buffer(struct printk_buffer *ptr, bool all)
+{
+ while (1) {
+ char *text = ptr->buf;
+ unsigned int text_len = ptr->used;
+ char *cp = memchr(text, '\n', text_len);
+ char c;
+
+ if (cp++)
+ text_len = cp - text;
+ else if (all)
+ cp = text + text_len;
+ else
+ break;
+ c = *cp;
+ *cp = '\0';
+ printk("%s", text);
+ ptr->used -= text_len;
+ if (!ptr->used)
+ break;
+ *cp = c;
+ memmove(text, text + text_len, ptr->used);
+ }
+}
+
+/*
+ * buffered_printk - Try to print multiple printk() calls as line oriented.
+ *
+ * This is a utility function for avoiding KERN_CONT and pr_cont() usage.
+ *
+ * Before:
+ *
+ * pr_info("INFO:");
+ * for (i = 0; i < 5; i++)
+ * pr_cont(" %s=%s", name[i], value[i]);
+ * pr_cont("\n");
+ *
+ * After:
+ *
+ * char buffer[256];
+ * DEFINE_PRINTK_BUFFER(buf, sizeof(buffer), buffer);
+ * buffered_printk(&buf, KERN_INFO "INFO:");
+ * for (i = 0; i < 5; i++)
+ * buffered_printk(&buf, " %s=%s", name[i], value[i]);
+ * buffered_printk(&buf, "\n");
+ *
+ * If the caller is not sure that the last buffered_printk() call ends with
+ * "\n", the caller can use flush_buffered_printk() in order to make sure that
+ * all data is passed to printk().
+ *
+ * If the buffer is not large enough to hold one line, buffered_printk() will
+ * fall back to regular printk() instead of truncating the data. But be careful
+ * with LOG_LINE_MAX limit anyway.
+ */
+asmlinkage __visible int buffered_printk(struct printk_buffer *ptr,
+ const char *fmt, ...)
+{
+ va_list args;
+ int r;
+ const unsigned int pos = ptr->used;
+
+ /* Try to store to printk_buffer first. */
+ va_start(args, fmt);
+ r = vsnprintf(ptr->buf + pos, ptr->size - pos, fmt, args);
+ va_end(args);
+ /* If it succeeds, process printk_buffer up to last '\n' and return. */
+ if (r + pos < ptr->size) {
+ ptr->used += r;
+ __flush_printk_buffer(ptr, false);
+ return r;
+ }
+ /* Otherwise, flush printk_buffer and use unbuffered printk(). */
+ __flush_printk_buffer(ptr, true);
+ va_start(args, fmt);
+ r = vprintk_func(fmt, args);
+ va_end(args);
+ return r;
+}
+EXPORT_SYMBOL(buffered_printk);
+
+void flush_buffered_printk(struct printk_buffer *ptr)
+{
+ __flush_printk_buffer(ptr, true);
+}
+EXPORT_SYMBOL(flush_buffered_printk);
+
#else /* CONFIG_PRINTK */

#define LOG_LINE_MAX 0
--
1.8.3.1