On (08/29/17 21:10), Steven Rostedt wrote:
[..]
> > could do. for a single continuation line printk("%.*s", s.len, s.buffer)
> > this will work perfectly fine. for a more general case - backtraces, dumps,
> > etc. - this requires some tweaks.
> 
> We could simply add a seq_buf_printk() that is implemented in the printk
> proper, to parse the seq_buf buffer properly, and add the timestamps and
> such.

so I quickly cooked the first version. like really quickly. just to
check if this is what people might like/use.

RFC.

so wondering if this will suffice. the name is somewhat hideous -- prbuf(),
wanted to keep it short and somehow aligned with pr_foo().

the patch also defines a number of prbuf_err()/prbuf_cont() macros that
call __prbuf_write() -- I don't want people to invoke __prbuf_write()
directly, because we need KERN_FOO prefix for stored messages and people
tend to forget to provide one.

prbuf_init() function inits the seq_buf buffer. it takes size and GFP
mask, just to permit prbuf usage from different contexts. if we fail
to kmalloc() the buffer, then __prbuf_write() does direct printk().

a usage example:


       struct seq_buf s;

       prbuf_init(&s, 256, GFP_KERNEL);

       prbuf_err(&s, "Opps at %lu\n", _RET_IP_);
       prbuf_info(&s, "Start of cont line");
       prbuf_cont(&s, " foo ");
       prbuf_cont(&s, " bar ");
       prbuf_cont(&s, " status: %s\n", "done");

       ret = 0;
       while (ret++ < 10)
               prbuf_err(&s, "%x\n", ret);

       prbuf_flush(&s);
       prbuf_free(&s);


this will store everything in conseq logbuf entries. if the buffer
was too small, we print overflow message.

any comments?

---
 include/linux/printk.h |  58 ++++++++++++++++
 kernel/printk/printk.c | 178 +++++++++++++++++++++++++++++++++++++++++--------
 2 files changed, 209 insertions(+), 27 deletions(-)

diff --git a/include/linux/printk.h b/include/linux/printk.h
index e10f27468322..ab39b85cff8e 100644
--- a/include/linux/printk.h
+++ b/include/linux/printk.h
@@ -206,6 +206,17 @@ void show_regs_print_info(const char *log_lvl);
 extern void printk_safe_init(void);
 extern void printk_safe_flush(void);
 extern void printk_safe_flush_on_panic(void);
+
+struct seq_buf;
+
+extern int prbuf_init(struct seq_buf *s, size_t size, gfp_t flags);
+
+extern __printf(2, 3) __cold
+int __prbuf_write(struct seq_buf *s, const char *fmt, ...);
+
+extern int prbuf_flush(struct seq_buf *s);
+
+extern void prbuf_free(struct seq_buf *s);
 #else
 static inline __printf(1, 0)
 int vprintk(const char *s, va_list args)
@@ -277,6 +288,29 @@ static inline void printk_safe_flush(void)
 static inline void printk_safe_flush_on_panic(void)
 {
 }
+
+struct seq_buf;
+
+static inline
+int prbuf_init(struct seq_buf *s, size_t size, gfp_t flags)
+{
+       return 0;
+}
+
+static inlin __printf(2, 3) __cold
+static int __prbuf_write(struct seq_buf *s, const char *fmt, ...)
+{
+       return 0;
+}
+
+static inline int prbuf_flush(struct seq_buf *s)
+{
+       return 0;
+}
+
+static inline void prbuf_free(struct seq_buf *s)
+{
+}
 #endif
 
 extern asmlinkage void dump_stack(void) __cold;
@@ -323,6 +357,30 @@ extern asmlinkage void dump_stack(void) __cold;
        no_printk(KERN_DEBUG pr_fmt(fmt), ##__VA_ARGS__)
 #endif
 
+/*
+ * Macros for buffered printk. All messages are stored in seq_buf instead of
+ * logbuf, user is required to flush the buffer in order to emit the messages
+ * and move them to the logbuf.
+ *
+ * Please use these macros and never call __prbuf_write() directly.
+ */
+#define prbuf_emerg(s, fmt, ...) \
+       __prbuf_write((s). KERN_EMERG pr_fmt(fmt), ##__VA_ARGS__)
+#define prbuf_alert(s, fmt, ...) \
+       __prbuf_write((s), KERN_ALERT pr_fmt(fmt), ##__VA_ARGS__)
+#define prbuf_crit(s, fmt, ...) \
+       __prbuf_write((s), KERN_CRIT pr_fmt(fmt), ##__VA_ARGS__)
+#define prbuf_err(s, fmt, ...) \
+       __prbuf_write((s), KERN_ERR pr_fmt(fmt), ##__VA_ARGS__)
+#define prbuf_warning(s, fmt, ...) \
+       __prbuf_write((s), KERN_WARNING pr_fmt(fmt), ##__VA_ARGS__)
+#define prbuf_warn pr_buf_warning
+#define prbuf_notice(s, fmt, ...) \
+       __prbuf_write((s), KERN_NOTICE pr_fmt(fmt), ##__VA_ARGS__)
+#define prbuf_info(s, fmt, ...) \
+       __prbuf_write((s), KERN_INFO pr_fmt(fmt), ##__VA_ARGS__)
+#define prbuf_cont(s, fmt, ...) \
+       __prbuf_write((s), KERN_CONT fmt, ##__VA_ARGS__)
 
 /* If you are writing a driver, please use dev_dbg instead */
 #if defined(CONFIG_DYNAMIC_DEBUG)
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 512f7c2baedd..6ccc7edda3a4 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -48,6 +48,7 @@
 #include <linux/sched/clock.h>
 #include <linux/sched/debug.h>
 #include <linux/sched/task_stack.h>
+#include <linux/seq_buf.h>
 
 #include <linux/uaccess.h>
 #include <asm/sections.h>
@@ -1651,7 +1652,9 @@ static bool cont_add(int facility, int level, enum 
log_flags flags, const char *
        return true;
 }
 
-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)
+static size_t log_output(int facility, int level, enum log_flags lflags,
+                        const char *dict, size_t dictlen,
+                        const char *text, size_t text_len)
 {
        /*
         * If an earlier line was buffered, and we're a continuation
@@ -1680,33 +1683,11 @@ static size_t log_output(int facility, int level, enum 
log_flags lflags, const c
        return log_store(facility, level, lflags, 0, dict, dictlen, text, 
text_len);
 }
 
-asmlinkage int vprintk_emit(int facility, int level,
-                           const char *dict, size_t dictlen,
-                           const char *fmt, va_list args)
+static int process_log(int facility, int level,
+                      const char *dict, size_t dictlen,
+                      const char *text, size_t text_len)
 {
-       static char textbuf[LOG_LINE_MAX];
-       char *text = textbuf;
-       size_t text_len;
        enum log_flags lflags = 0;
-       unsigned long flags;
-       int printed_len;
-       bool in_sched = false;
-
-       if (level == LOGLEVEL_SCHED) {
-               level = LOGLEVEL_DEFAULT;
-               in_sched = true;
-       }
-
-       boot_delay_msec(level);
-       printk_delay();
-
-       /* This stops the holder of console_sem just where we want him */
-       logbuf_lock_irqsave(flags);
-       /*
-        * The printf needs to come first; we need the syslog
-        * prefix which might be passed-in as a parameter.
-        */
-       text_len = vscnprintf(text, sizeof(textbuf), fmt, args);
 
        /* mark and strip a trailing newline */
        if (text_len && text[text_len-1] == '\n') {
@@ -1742,8 +1723,38 @@ asmlinkage int vprintk_emit(int facility, int level,
        if (dict)
                lflags |= LOG_PREFIX|LOG_NEWLINE;
 
-       printed_len = log_output(facility, level, lflags, dict, dictlen, text, 
text_len);
+       return log_output(facility, level, lflags, dict, dictlen, text, 
text_len);
+}
+
+asmlinkage int vprintk_emit(int facility, int level,
+                           const char *dict, size_t dictlen,
+                           const char *fmt, va_list args)
+{
+       static char textbuf[LOG_LINE_MAX];
+       char *text = textbuf;
+       size_t text_len;
+       unsigned long flags;
+       int printed_len;
+       bool in_sched = false;
+
+       if (level == LOGLEVEL_SCHED) {
+               level = LOGLEVEL_DEFAULT;
+               in_sched = true;
+       }
+
+       boot_delay_msec(level);
+       printk_delay();
 
+       /* This stops the holder of console_sem just where we want him */
+       logbuf_lock_irqsave(flags);
+       /*
+        * The printf needs to come first; we need the syslog
+        * prefix which might be passed-in as a parameter.
+        */
+       text_len = vscnprintf(text, sizeof(textbuf), fmt, args);
+       printed_len = process_log(facility, level,
+                                 dict, dictlen,
+                                 text, text_len);
        logbuf_unlock_irqrestore(flags);
 
        /* If called from the scheduler, we can not call up(). */
@@ -1833,6 +1844,119 @@ asmlinkage __visible int printk(const char *fmt, ...)
 }
 EXPORT_SYMBOL(printk);
 
+int prbuf_init(struct seq_buf *s, size_t size, gfp_t flags)
+{
+       char *b;
+
+       b = kmalloc(size, flags);
+       seq_buf_init(s, b, size);
+       return !!b;
+}
+EXPORT_SYMBOL(prbuf_init);
+
+/*
+ * Do not use this function directly. Use dedicated macros instead.
+ *
+ * If you'll you use this function, Linus will kindly ask you to
+ * consider other options.
+ */
+int __prbuf_write(struct seq_buf *s, const char *fmt, ...)
+{
+       va_list args;
+       int r;
+
+       va_start(args, fmt);
+       if (likely(s->buffer))
+               r = seq_buf_vprintf(s, fmt, args);
+       else
+               r = vprintk_func(fmt, args);
+       va_end(args);
+
+       return r;
+}
+EXPORT_SYMBOL(__prbuf_write);
+
+int prbuf_flush(struct seq_buf *s)
+{
+       unsigned long flags;
+       const char *start, *c, *end;
+       bool header;
+       int len = 0;
+
+       if (!s->buffer)
+               return 0;
+
+       start = s->buffer;
+       c = start;
+       end = start + seq_buf_used(s);
+       header = true;
+
+       logbuf_lock_irqsave(flags);
+
+       if (seq_buf_has_overflowed(s)) {
+               static const char *msg = KERN_ERR "Print buffer overflow\n";
+
+               len += process_log(0, LOGLEVEL_DEFAULT,
+                                  NULL, 0,
+                                  msg, strlen(msg));
+       }
+
+       /* Print line by line. */
+       while (c < end) {
+               if (*c == '\n') {
+                       len += process_log(0, LOGLEVEL_DEFAULT,
+                                          NULL, 0,
+                                          start, c - start + 1);
+                       start = ++c;
+                       header = true;
+                       continue;
+               }
+
+               /* Handle continuous lines or missing new line. */
+               if ((c + 1 < end) && printk_get_level(c)) {
+                       if (header) {
+                               c = printk_skip_level(c);
+                               continue;
+                       }
+
+                       len += process_log(0, LOGLEVEL_DEFAULT,
+                                          NULL, 0,
+                                          start, c - start);
+                       start = c++;
+                       header = true;
+                       continue;
+               }
+
+               header = false;
+               c++;
+       }
+
+       /* Check if there was a partial line. Ignore pure header. */
+       if (start < end && !header) {
+               static const char *newline = KERN_CONT "\n";
+
+               len += process_log(0, LOGLEVEL_DEFAULT,
+                                  NULL, 0,
+                                  start, end - start);
+               len += process_log(0, LOGLEVEL_DEFAULT,
+                                  NULL, 0,
+                                  newline, strlen(newline));
+       }
+
+       logbuf_unlock_irqrestore(flags);
+
+       seq_buf_clear(s);
+       return len;
+}
+EXPORT_SYMBOL(prbuf_flush);
+
+void prbuf_free(struct seq_buf *s)
+{
+       kfree(s->buffer);
+       seq_buf_init(s, NULL, 0);
+}
+EXPORT_SYMBOL(prbuf_free);
+
 #else /* CONFIG_PRINTK */
 
 #define LOG_LINE_MAX           0
-- 
2.14.1

Reply via email to