| From: John Ogness <john.ogness@linutronix.de> |
| Date: Tue, 12 Feb 2019 15:30:02 +0100 |
| Subject: [PATCH 24/25] printk: implement kmsg_dump |
| |
| Since printk messages are now logged to a new ring buffer, update |
| the kmsg_dump functions to pull the messages from there. |
| |
| Signed-off-by: John Ogness <john.ogness@linutronix.de> |
| Signed-off-by: Sebastian Andrzej Siewior <bigeasy@linutronix.de> |
| --- |
| include/linux/kmsg_dump.h | 6 - |
| kernel/printk/printk.c | 258 ++++++++++++++++++++++++---------------------- |
| 2 files changed, 139 insertions(+), 125 deletions(-) |
| |
| --- a/include/linux/kmsg_dump.h |
| +++ b/include/linux/kmsg_dump.h |
| @@ -46,10 +46,8 @@ struct kmsg_dumper { |
| bool registered; |
| |
| /* private state of the kmsg iterator */ |
| - u32 cur_idx; |
| - u32 next_idx; |
| - u64 cur_seq; |
| - u64 next_seq; |
| + u64 line_seq; |
| + u64 buffer_end_seq; |
| }; |
| |
| #ifdef CONFIG_PRINTK |
| --- a/kernel/printk/printk.c |
| +++ b/kernel/printk/printk.c |
| @@ -417,13 +417,13 @@ static size_t syslog_partial; |
| static bool syslog_time; |
| |
| /* index and sequence number of the first record stored in the buffer */ |
| -static u64 log_first_seq; |
| static u32 log_first_idx; |
| |
| /* index and sequence number of the next record to store in the buffer */ |
| -static u64 log_next_seq; |
| static u32 log_next_idx; |
| |
| +static DEFINE_MUTEX(kmsg_dump_lock); |
| + |
| /* the next printk record to read after the last 'clear' command */ |
| static u64 clear_seq; |
| static u32 clear_idx; |
| @@ -470,38 +470,6 @@ static char *log_dict(const struct print |
| return (char *)msg + sizeof(struct printk_log) + msg->text_len; |
| } |
| |
| -/* get record by index; idx must point to valid msg */ |
| -static struct printk_log *log_from_idx(u32 idx) |
| -{ |
| - struct printk_log *msg = (struct printk_log *)(log_buf + idx); |
| - |
| - /* |
| - * A length == 0 record is the end of buffer marker. Wrap around and |
| - * read the message at the start of the buffer. |
| - */ |
| - if (!msg->len) |
| - return (struct printk_log *)log_buf; |
| - return msg; |
| -} |
| - |
| -/* get next record; idx must point to valid msg */ |
| -static u32 log_next(u32 idx) |
| -{ |
| - struct printk_log *msg = (struct printk_log *)(log_buf + idx); |
| - |
| - /* length == 0 indicates the end of the buffer; wrap */ |
| - /* |
| - * A length == 0 record is the end of buffer marker. Wrap around and |
| - * read the message at the start of the buffer as *this* one, and |
| - * return the one after that. |
| - */ |
| - if (!msg->len) { |
| - msg = (struct printk_log *)log_buf; |
| - return msg->len; |
| - } |
| - return idx + msg->len; |
| -} |
| - |
| static void printk_emergency(char *buffer, int level, u64 ts_nsec, u16 cpu, |
| char *text, u16 text_len); |
| |
| @@ -2120,9 +2088,7 @@ EXPORT_SYMBOL(printk); |
| #define printk_time false |
| |
| static u64 syslog_seq; |
| -static u64 log_first_seq; |
| static u32 log_first_idx; |
| -static u64 log_next_seq; |
| static char *log_text(const struct printk_log *msg) { return NULL; } |
| static char *log_dict(const struct printk_log *msg) { return NULL; } |
| static struct printk_log *log_from_idx(u32 idx) { return NULL; } |
| @@ -3033,7 +2999,6 @@ module_param_named(always_kmsg_dump, alw |
| void kmsg_dump(enum kmsg_dump_reason reason) |
| { |
| struct kmsg_dumper *dumper; |
| - unsigned long flags; |
| |
| if ((reason > KMSG_DUMP_OOPS) && !always_kmsg_dump) |
| return; |
| @@ -3046,12 +3011,7 @@ void kmsg_dump(enum kmsg_dump_reason rea |
| /* initialize iterator with data about the stored records */ |
| dumper->active = true; |
| |
| - logbuf_lock_irqsave(flags); |
| - dumper->cur_seq = clear_seq; |
| - dumper->cur_idx = clear_idx; |
| - dumper->next_seq = log_next_seq; |
| - dumper->next_idx = log_next_idx; |
| - logbuf_unlock_irqrestore(flags); |
| + kmsg_dump_rewind(dumper); |
| |
| /* invoke dumper which will iterate over records */ |
| dumper->dump(dumper, reason); |
| @@ -3084,33 +3044,67 @@ void kmsg_dump(enum kmsg_dump_reason rea |
| bool kmsg_dump_get_line_nolock(struct kmsg_dumper *dumper, bool syslog, |
| char *line, size_t size, size_t *len) |
| { |
| + struct prb_iterator iter; |
| struct printk_log *msg; |
| - size_t l = 0; |
| - bool ret = false; |
| + struct prb_handle h; |
| + bool cont = false; |
| + char *msgbuf; |
| + char *rbuf; |
| + size_t l; |
| + u64 seq; |
| + int ret; |
| |
| if (!dumper->active) |
| - goto out; |
| + return cont; |
| + |
| + rbuf = prb_reserve(&h, &sprint_rb, PRINTK_RECORD_MAX); |
| + if (!rbuf) |
| + return cont; |
| + msgbuf = rbuf; |
| +retry: |
| + for (;;) { |
| + prb_iter_init(&iter, &printk_rb, &seq); |
| + |
| + if (dumper->line_seq == seq) { |
| + /* already where we want to be */ |
| + break; |
| + } else if (dumper->line_seq < seq) { |
| + /* messages are gone, move to first available one */ |
| + dumper->line_seq = seq; |
| + break; |
| + } |
| |
| - if (dumper->cur_seq < log_first_seq) { |
| - /* messages are gone, move to first available one */ |
| - dumper->cur_seq = log_first_seq; |
| - dumper->cur_idx = log_first_idx; |
| + ret = prb_iter_seek(&iter, dumper->line_seq); |
| + if (ret > 0) { |
| + /* seeked to line_seq */ |
| + break; |
| + } else if (ret == 0) { |
| + /* |
| + * The end of the list was hit without ever seeing |
| + * line_seq. Reset it to the beginning of the list. |
| + */ |
| + prb_iter_init(&iter, &printk_rb, &dumper->line_seq); |
| + break; |
| + } |
| + /* iterator invalid, start over */ |
| } |
| |
| - /* last entry */ |
| - if (dumper->cur_seq >= log_next_seq) |
| + ret = prb_iter_next(&iter, msgbuf, PRINTK_RECORD_MAX, |
| + &dumper->line_seq); |
| + if (ret == 0) |
| goto out; |
| + else if (ret < 0) |
| + goto retry; |
| |
| - msg = log_from_idx(dumper->cur_idx); |
| + msg = (struct printk_log *)msgbuf; |
| l = msg_print_text(msg, syslog, printk_time, line, size); |
| |
| - dumper->cur_idx = log_next(dumper->cur_idx); |
| - dumper->cur_seq++; |
| - ret = true; |
| -out: |
| if (len) |
| *len = l; |
| - return ret; |
| + cont = true; |
| +out: |
| + prb_commit(&h); |
| + return cont; |
| } |
| |
| /** |
| @@ -3133,12 +3127,11 @@ bool kmsg_dump_get_line_nolock(struct km |
| bool kmsg_dump_get_line(struct kmsg_dumper *dumper, bool syslog, |
| char *line, size_t size, size_t *len) |
| { |
| - unsigned long flags; |
| bool ret; |
| |
| - logbuf_lock_irqsave(flags); |
| + mutex_lock(&kmsg_dump_lock); |
| ret = kmsg_dump_get_line_nolock(dumper, syslog, line, size, len); |
| - logbuf_unlock_irqrestore(flags); |
| + mutex_unlock(&kmsg_dump_lock); |
| |
| return ret; |
| } |
| @@ -3166,74 +3159,101 @@ EXPORT_SYMBOL_GPL(kmsg_dump_get_line); |
| bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog, |
| char *buf, size_t size, size_t *len) |
| { |
| - unsigned long flags; |
| - u64 seq; |
| - u32 idx; |
| - u64 next_seq; |
| - u32 next_idx; |
| - size_t l = 0; |
| - bool ret = false; |
| + struct prb_iterator iter; |
| bool time = printk_time; |
| + struct printk_log *msg; |
| + u64 new_end_seq = 0; |
| + struct prb_handle h; |
| + bool cont = false; |
| + char *msgbuf; |
| + u64 end_seq; |
| + int textlen; |
| + u64 seq = 0; |
| + char *rbuf; |
| + int l = 0; |
| + int ret; |
| |
| if (!dumper->active) |
| - goto out; |
| + return cont; |
| |
| - logbuf_lock_irqsave(flags); |
| - if (dumper->cur_seq < log_first_seq) { |
| - /* messages are gone, move to first available one */ |
| - dumper->cur_seq = log_first_seq; |
| - dumper->cur_idx = log_first_idx; |
| - } |
| + rbuf = prb_reserve(&h, &sprint_rb, PRINTK_RECORD_MAX); |
| + if (!rbuf) |
| + return cont; |
| + msgbuf = rbuf; |
| |
| - /* last entry */ |
| - if (dumper->cur_seq >= dumper->next_seq) { |
| - logbuf_unlock_irqrestore(flags); |
| - goto out; |
| - } |
| - |
| - /* calculate length of entire buffer */ |
| - seq = dumper->cur_seq; |
| - idx = dumper->cur_idx; |
| - while (seq < dumper->next_seq) { |
| - struct printk_log *msg = log_from_idx(idx); |
| + prb_iter_init(&iter, &printk_rb, NULL); |
| |
| - l += msg_print_text(msg, true, time, NULL, 0); |
| - idx = log_next(idx); |
| - seq++; |
| + /* |
| + * seek to the start record, which is set/modified |
| + * by kmsg_dump_get_line_nolock() |
| + */ |
| + ret = prb_iter_seek(&iter, dumper->line_seq); |
| + if (ret <= 0) |
| + prb_iter_init(&iter, &printk_rb, &seq); |
| + |
| + /* work with a local end seq to have a constant value */ |
| + end_seq = dumper->buffer_end_seq; |
| + if (!end_seq) { |
| + /* initialize end seq to "infinity" */ |
| + end_seq = -1; |
| + dumper->buffer_end_seq = end_seq; |
| } |
| +retry: |
| + if (seq >= end_seq) |
| + goto out; |
| |
| - /* move first record forward until length fits into the buffer */ |
| - seq = dumper->cur_seq; |
| - idx = dumper->cur_idx; |
| - while (l >= size && seq < dumper->next_seq) { |
| - struct printk_log *msg = log_from_idx(idx); |
| + /* count the total bytes after seq */ |
| + textlen = count_remaining(&iter, end_seq, msgbuf, |
| + PRINTK_RECORD_MAX, 0, time); |
| |
| - l -= msg_print_text(msg, true, time, NULL, 0); |
| - idx = log_next(idx); |
| - seq++; |
| + /* move iter forward until length fits into the buffer */ |
| + while (textlen > size) { |
| + ret = prb_iter_next(&iter, msgbuf, PRINTK_RECORD_MAX, &seq); |
| + if (ret == 0) { |
| + break; |
| + } else if (ret < 0) { |
| + prb_iter_init(&iter, &printk_rb, &seq); |
| + goto retry; |
| + } |
| + |
| + msg = (struct printk_log *)msgbuf; |
| + textlen -= msg_print_text(msg, true, time, NULL, 0); |
| } |
| |
| - /* last message in next interation */ |
| - next_seq = seq; |
| - next_idx = idx; |
| + /* save end seq for the next interation */ |
| + new_end_seq = seq + 1; |
| |
| - l = 0; |
| - while (seq < dumper->next_seq) { |
| - struct printk_log *msg = log_from_idx(idx); |
| + /* copy messages to buffer */ |
| + while (l < size) { |
| + ret = prb_iter_next(&iter, msgbuf, PRINTK_RECORD_MAX, &seq); |
| + if (ret == 0) { |
| + break; |
| + } else if (ret < 0) { |
| + /* |
| + * iterator (and thus also the start position) |
| + * invalid, start over from beginning of list |
| + */ |
| + prb_iter_init(&iter, &printk_rb, NULL); |
| + continue; |
| + } |
| |
| - l += msg_print_text(msg, syslog, time, buf + l, size - l); |
| - idx = log_next(idx); |
| - seq++; |
| + if (seq >= end_seq) |
| + break; |
| + |
| + msg = (struct printk_log *)msgbuf; |
| + textlen = msg_print_text(msg, syslog, time, buf + l, size - l); |
| + if (textlen > 0) |
| + l += textlen; |
| + cont = true; |
| } |
| |
| - dumper->next_seq = next_seq; |
| - dumper->next_idx = next_idx; |
| - ret = true; |
| - logbuf_unlock_irqrestore(flags); |
| -out: |
| - if (len) |
| + if (cont && len) |
| *len = l; |
| - return ret; |
| +out: |
| + prb_commit(&h); |
| + if (new_end_seq) |
| + dumper->buffer_end_seq = new_end_seq; |
| + return cont; |
| } |
| EXPORT_SYMBOL_GPL(kmsg_dump_get_buffer); |
| |
| @@ -3249,10 +3269,8 @@ EXPORT_SYMBOL_GPL(kmsg_dump_get_buffer); |
| */ |
| void kmsg_dump_rewind_nolock(struct kmsg_dumper *dumper) |
| { |
| - dumper->cur_seq = clear_seq; |
| - dumper->cur_idx = clear_idx; |
| - dumper->next_seq = log_next_seq; |
| - dumper->next_idx = log_next_idx; |
| + dumper->line_seq = 0; |
| + dumper->buffer_end_seq = 0; |
| } |
| |
| /** |
| @@ -3265,11 +3283,9 @@ void kmsg_dump_rewind_nolock(struct kmsg |
| */ |
| void kmsg_dump_rewind(struct kmsg_dumper *dumper) |
| { |
| - unsigned long flags; |
| - |
| - logbuf_lock_irqsave(flags); |
| + mutex_lock(&kmsg_dump_lock); |
| kmsg_dump_rewind_nolock(dumper); |
| - logbuf_unlock_irqrestore(flags); |
| + mutex_unlock(&kmsg_dump_lock); |
| } |
| EXPORT_SYMBOL_GPL(kmsg_dump_rewind); |
| |