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