History

kmsg - kmsg_dump() use iterator to receive log buffer content

Provide an iterator to receive the log buffer content, and convert all kmsg_dump() users to it. The structured data in the kmsg buffer now contains binary data, which should no longer be copied verbatim to the kmsg_dump() users. The iterator should provide reliable access to the buffer data, and also supports proper log line-aware chunking of data while iterating.

Kay Sievers committed 14 years ago

Commit e2ae7151 parent 1bd289d6 files · +258 −137Browse files

Unified · Split

6 files
  1. arch/powerpc/platforms/pseries/nvram.c +7 −54
  2. arch/x86/platform/mrst/early_printk_mrst.c +5 −8
  3. drivers/mtd/mtdoops.c +4 −18
  4. fs/pstore/platform.c +12 −22
  5. include/linux/kmsg_dump.h +38 −7
  6. kernel/printk.c +192 −28
arch/powerpc/platforms/pseries/nvram.c+7−54
@@ -68,9 +68,7 @@ static const char *pseries_nvram_os_partitions[] = { · 67 unmodified lines
6868 };
6969
7070 static void oops_to_nvram(struct kmsg_dumper *dumper,
71− enum kmsg_dump_reason reason,
72− const char *old_msgs, unsigned long old_len,
73− const char *new_msgs, unsigned long new_len);
71+ enum kmsg_dump_reason reason);
7472
7573 static struct kmsg_dumper nvram_kmsg_dumper = {
7674 .dump = oops_to_nvram
@@ -503,28 +501,6 @@ int __init pSeries_nvram_init(void) · 426 unmodified lines
503501 return 0;
504502 }
505503
506−/*
507− * Try to capture the last capture_len bytes of the printk buffer. Return
508− * the amount actually captured.
509− */
510−static size_t capture_last_msgs(const char *old_msgs, size_t old_len,
511− const char *new_msgs, size_t new_len,
512− char *captured, size_t capture_len)
513−{
514− if (new_len >= capture_len) {
515− memcpy(captured, new_msgs + (new_len - capture_len),
516− capture_len);
517− return capture_len;
518− } else {
519− /* Grab the end of old_msgs. */
520− size_t old_tail_len = min(old_len, capture_len - new_len);
521− memcpy(captured, old_msgs + (old_len - old_tail_len),
522− old_tail_len);
523− memcpy(captured + old_tail_len, new_msgs, new_len);
524− return old_tail_len + new_len;
525− }
526−}
527−
528504 /*
529505 * Are we using the ibm,rtas-log for oops/panic reports? And if so,
530506 * would logging this oops/panic overwrite an RTAS event that rtas_errd
@@ -541,27 +517,6 @@ static int clobbering_unread_rtas_event(void) · 10 unmodified lines
541517 NVRAM_RTAS_READ_TIMEOUT);
542518 }
543519
544−/* Squeeze out each line's <n> severity prefix. */
545−static size_t elide_severities(char *buf, size_t len)
546−{
547− char *in, *out, *buf_end = buf + len;
548− /* Assume a <n> at the very beginning marks the start of a line. */
549− int newline = 1;
550−
551− in = out = buf;
552− while (in < buf_end) {
553− if (newline && in+3 <= buf_end &&
554− *in == '<' && isdigit(in[1]) && in[2] == '>') {
555− in += 3;
556− newline = 0;
557− } else {
558− newline = (*in == '\n');
559− *out++ = *in++;
560− }
561− }
562− return out - buf;
563−}
564−
565520 /* Derived from logfs_compress() */
566521 static int nvram_compress(const void *in, void *out, size_t inlen,
567522 size_t outlen)
@@ -619,9 +574,7 @@ static int zip_oops(size_t text_len) · 51 unmodified lines
619574 * partition. If that's too much, go back and capture uncompressed text.
620575 */
621576 static void oops_to_nvram(struct kmsg_dumper *dumper,
622− enum kmsg_dump_reason reason,
623− const char *old_msgs, unsigned long old_len,
624− const char *new_msgs, unsigned long new_len)
577+ enum kmsg_dump_reason reason)
625578 {
626579 static unsigned int oops_count = 0;
627580 static bool panicking = false;
@@ -660,14 +613,14 @@ static void oops_to_nvram(struct kmsg_dumper *dumper, · 32 unmodified lines
660613 return;
661614
662615 if (big_oops_buf) {
663− text_len = capture_last_msgs(old_msgs, old_len,
664− new_msgs, new_len, big_oops_buf, big_oops_buf_sz);
665− text_len = elide_severities(big_oops_buf, text_len);
616+ kmsg_dump_get_buffer(dumper, false,
617+ big_oops_buf, big_oops_buf_sz, &text_len);
666618 rc = zip_oops(text_len);
667619 }
668620 if (rc != 0) {
669− text_len = capture_last_msgs(old_msgs, old_len,
670− new_msgs, new_len, oops_data, oops_data_sz);
621+ kmsg_dump_rewind(dumper);
622+ kmsg_dump_get_buffer(dumper, true,
623+ oops_data, oops_data_sz, &text_len);
671624 err_type = ERR_TYPE_KERNEL_PANIC;
672625 *oops_len = (u16) text_len;
673626 }
arch/x86/platform/mrst/early_printk_mrst.c+5−8
@@ -110,19 +110,16 @@ static struct kmsg_dumper dw_dumper; · 109 unmodified lines
110110 static int dumper_registered;
111111
112112 static void dw_kmsg_dump(struct kmsg_dumper *dumper,
113− enum kmsg_dump_reason reason,
114− const char *s1, unsigned long l1,
115− const char *s2, unsigned long l2)
113+ enum kmsg_dump_reason reason)
116114 {
117− int i;
115+ static char line[1024];
116+ size_t len;
118117
119118 /* When run to this, we'd better re-init the HW */
120119 mrst_early_console_init();
121120
122− for (i = 0; i < l1; i++)
123− early_mrst_console.write(&early_mrst_console, s1 + i, 1);
124− for (i = 0; i < l2; i++)
125− early_mrst_console.write(&early_mrst_console, s2 + i, 1);
121+ while (kmsg_dump_get_line(dumper, true, line, sizeof(line), &len))
122+ early_mrst_console.write(&early_mrst_console, line, len);
126123 }
127124
128125 /* Set the ratio rate to 115200, 8n1, IRQ disabled */
drivers/mtd/mtdoops.c+4−18
@@ -304,32 +304,17 @@ static void find_next_position(struct mtdoops_context *cxt) · 303 unmodified lines
304304 }
305305
306306 static void mtdoops_do_dump(struct kmsg_dumper *dumper,
307− enum kmsg_dump_reason reason, const char *s1, unsigned long l1,
308− const char *s2, unsigned long l2)
307+ enum kmsg_dump_reason reason)
309308 {
310309 struct mtdoops_context *cxt = container_of(dumper,
311310 struct mtdoops_context, dump);
312− unsigned long s1_start, s2_start;
313− unsigned long l1_cpy, l2_cpy;
314− char *dst;
315−
316− if (reason != KMSG_DUMP_OOPS &&
317− reason != KMSG_DUMP_PANIC)
318− return;
319311
320312 /* Only dump oopses if dump_oops is set */
321313 if (reason == KMSG_DUMP_OOPS && !dump_oops)
322314 return;
323315
324− dst = cxt->oops_buf + MTDOOPS_HEADER_SIZE; /* Skip the header */
325− l2_cpy = min(l2, record_size - MTDOOPS_HEADER_SIZE);
326− l1_cpy = min(l1, record_size - MTDOOPS_HEADER_SIZE - l2_cpy);
327−
328− s2_start = l2 - l2_cpy;
329− s1_start = l1 - l1_cpy;
330−
331− memcpy(dst, s1 + s1_start, l1_cpy);
332− memcpy(dst + l1_cpy, s2 + s2_start, l2_cpy);
316+ kmsg_dump_get_buffer(dumper, true, cxt->oops_buf + MTDOOPS_HEADER_SIZE,
317+ record_size - MTDOOPS_HEADER_SIZE, NULL);
333318
334319 /* Panics must be written immediately */
335320 if (reason != KMSG_DUMP_OOPS)
@@ -375,6 +360,7 @@ static void mtdoops_notify_add(struct mtd_info *mtd) · 39 unmodified lines
375360 return;
376361 }
377362
363+ cxt->dump.max_reason = KMSG_DUMP_OOPS;
378364 cxt->dump.dump = mtdoops_do_dump;
379365 err = kmsg_dump_register(&cxt->dump);
380366 if (err) {
fs/pstore/platform.c+12−22
@@ -94,20 +94,15 @@ static const char *get_reason_str(enum kmsg_dump_reason reason) · 93 unmodified lines
9494 * as we can from the end of the buffer.
9595 */
9696 static void pstore_dump(struct kmsg_dumper *dumper,
97− enum kmsg_dump_reason reason,
98− const char *s1, unsigned long l1,
99− const char *s2, unsigned long l2)
97+ enum kmsg_dump_reason reason)
10098 {
101− unsigned long s1_start, s2_start;
102− unsigned long l1_cpy, l2_cpy;
103− unsigned long size, total = 0;
104− char *dst;
99+ unsigned long total = 0;
105100 const char *why;
106101 u64 id;
107− int hsize, ret;
108102 unsigned int part = 1;
109103 unsigned long flags = 0;
110104 int is_locked = 0;
105+ int ret;
111106
112107 why = get_reason_str(reason);
113108
@@ -119,30 +114,25 @@ static void pstore_dump(struct kmsg_dumper *dumper, · 5 unmodified lines
119114 spin_lock_irqsave(&psinfo->buf_lock, flags);
120115 oopscount++;
121116 while (total < kmsg_bytes) {
117+ char *dst;
118+ unsigned long size;
119+ int hsize;
120+ size_t len;
121+
122122 dst = psinfo->buf;
123123 hsize = sprintf(dst, "%s#%d Part%d\n", why, oopscount, part);
124124 size = psinfo->bufsize - hsize;
125125 dst += hsize;
126126
127− l2_cpy = min(l2, size);
128− l1_cpy = min(l1, size - l2_cpy);
129−
130− if (l1_cpy + l2_cpy == 0)
127+ if (!kmsg_dump_get_buffer(dumper, true, dst, size, &len))
131128 break;
132129
133− s2_start = l2 - l2_cpy;
134− s1_start = l1 - l1_cpy;
135−
136− memcpy(dst, s1 + s1_start, l1_cpy);
137− memcpy(dst + l1_cpy, s2 + s2_start, l2_cpy);
138−
139130 ret = psinfo->write(PSTORE_TYPE_DMESG, reason, &id, part,
140− hsize + l1_cpy + l2_cpy, psinfo);
131+ hsize + len, psinfo);
141132 if (ret == 0 && reason == KMSG_DUMP_OOPS && pstore_is_mounted())
142133 pstore_new_entry = 1;
143− l1 -= l1_cpy;
144− l2 -= l2_cpy;
145− total += l1_cpy + l2_cpy;
134+
135+ total += hsize + len;
146136 part++;
147137 }
148138 if (in_nmi()) {
include/linux/kmsg_dump.h+38−7
@@ -21,6 +21,7 @@ · 20 unmodified lines
2121 * is passed to the kernel.
2222 */
2323 enum kmsg_dump_reason {
24+ KMSG_DUMP_UNDEF,
2425 KMSG_DUMP_PANIC,
2526 KMSG_DUMP_OOPS,
2627 KMSG_DUMP_EMERG,
@@ -31,23 +32,37 @@ enum kmsg_dump_reason { · 4 unmodified lines
3132
3233 /**
3334 * struct kmsg_dumper - kernel crash message dumper structure
34− * @dump: The callback which gets called on crashes. The buffer is passed
35− * as two sections, where s1 (length l1) contains the older
36− * messages and s2 (length l2) contains the newer.
3735 * @list: Entry in the dumper list (private)
36+ * @dump: Call into dumping code which will retrieve the data with
37+ * through the record iterator
38+ * @max_reason: filter for highest reason number that should be dumped
3839 * @registered: Flag that specifies if this is already registered
3940 */
4041 struct kmsg_dumper {
41− void (*dump)(struct kmsg_dumper *dumper, enum kmsg_dump_reason reason,
42− const char *s1, unsigned long l1,
43− const char *s2, unsigned long l2);
4442 struct list_head list;
45− int registered;
43+ void (*dump)(struct kmsg_dumper *dumper, enum kmsg_dump_reason reason);
44+ enum kmsg_dump_reason max_reason;
45+ bool active;
46+ bool registered;
47+
48+ /* private state of the kmsg iterator */
49+ u32 cur_idx;
50+ u32 next_idx;
51+ u64 cur_seq;
52+ u64 next_seq;
4653 };
4754
4855 #ifdef CONFIG_PRINTK
4956 void kmsg_dump(enum kmsg_dump_reason reason);
5057
58+bool kmsg_dump_get_line(struct kmsg_dumper *dumper, bool syslog,
59+ char *line, size_t size, size_t *len);
60+
61+bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
62+ char *buf, size_t size, size_t *len);
63+
64+void kmsg_dump_rewind(struct kmsg_dumper *dumper);
65+
5166 int kmsg_dump_register(struct kmsg_dumper *dumper);
5267
5368 int kmsg_dump_unregister(struct kmsg_dumper *dumper);
@@ -56,6 +71,22 @@ static inline void kmsg_dump(enum kmsg_dump_reason reason) · 2 unmodified lines
5671 {
5772 }
5873
74+bool kmsg_dump_get_line(struct kmsg_dumper *dumper, bool syslog,
75+ const char *line, size_t size, size_t *len)
76+{
77+ return false;
78+}
79+
80+bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
81+ char *buf, size_t size, size_t *len)
82+{
83+ return false;
84+}
85+
86+void kmsg_dump_rewind(struct kmsg_dumper *dumper)
87+{
88+}
89+
5990 static inline int kmsg_dump_register(struct kmsg_dumper *dumper)
6091 {
6192 return -EINVAL;
kernel/printk.c+192−28
@@ -909,7 +909,7 @@ static int syslog_print_all(char __user *buf, int size, bool clear) · 908 unmodified lines
909909 /*
910910 * Find first record that fits, including all following records,
911911 * into the user-provided buffer for this dump.
912− */
912+ */
913913 seq = clear_seq;
914914 idx = clear_idx;
915915 while (seq < log_next_seq) {
@@ -919,6 +919,8 @@ static int syslog_print_all(char __user *buf, int size, bool clear) · 3 unmodified lines
919919 idx = log_next(idx);
920920 seq++;
921921 }
922+
923+ /* move first record forward until length fits into the buffer */
922924 seq = clear_seq;
923925 idx = clear_idx;
924926 while (len > size && seq < log_next_seq) {
@@ -929,7 +931,7 @@ static int syslog_print_all(char __user *buf, int size, bool clear) · 4 unmodified lines
929931 seq++;
930932 }
931933
932− /* last message in this dump */
934+ /* last message fitting into this dump */
933935 next_seq = log_next_seq;
934936
935937 len = 0;
@@ -2300,48 +2302,210 @@ module_param_named(always_kmsg_dump, always_kmsg_dump, bool, S_IRUGO | S_IWUSR); · 1364 unmodified lines
23002302 * kmsg_dump - dump kernel log to kernel message dumpers.
23012303 * @reason: the reason (oops, panic etc) for dumping
23022304 *
2303− * Iterate through each of the dump devices and call the oops/panic
2304− * callbacks with the log buffer.
2305+ * Call each of the registered dumper's dump() callback, which can
2306+ * retrieve the kmsg records with kmsg_dump_get_line() or
2307+ * kmsg_dump_get_buffer().
23052308 */
23062309 void kmsg_dump(enum kmsg_dump_reason reason)
23072310 {
2308− u64 idx;
23092311 struct kmsg_dumper *dumper;
2310− const char *s1, *s2;
2311− unsigned long l1, l2;
23122312 unsigned long flags;
23132313
23142314 if ((reason > KMSG_DUMP_OOPS) && !always_kmsg_dump)
23152315 return;
23162316
2317− /* Theoretically, the log could move on after we do this, but
2318− there's not a lot we can do about that. The new messages
2319− will overwrite the start of what we dump. */
2317+ rcu_read_lock();
2318+ list_for_each_entry_rcu(dumper, &dump_list, list) {
2319+ if (dumper->max_reason && reason > dumper->max_reason)
2320+ continue;
2321+
2322+ /* initialize iterator with data about the stored records */
2323+ dumper->active = true;
2324+
2325+ raw_spin_lock_irqsave(&logbuf_lock, flags);
2326+ dumper->cur_seq = clear_seq;
2327+ dumper->cur_idx = clear_idx;
2328+ dumper->next_seq = log_next_seq;
2329+ dumper->next_idx = log_next_idx;
2330+ raw_spin_unlock_irqrestore(&logbuf_lock, flags);
2331+
2332+ /* invoke dumper which will iterate over records */
2333+ dumper->dump(dumper, reason);
2334+
2335+ /* reset iterator */
2336+ dumper->active = false;
2337+ }
2338+ rcu_read_unlock();
2339+}
2340+
2341+/**
2342+ * kmsg_dump_get_line - retrieve one kmsg log line
2343+ * @dumper: registered kmsg dumper
2344+ * @syslog: include the "<4>" prefixes
2345+ * @line: buffer to copy the line to
2346+ * @size: maximum size of the buffer
2347+ * @len: length of line placed into buffer
2348+ *
2349+ * Start at the beginning of the kmsg buffer, with the oldest kmsg
2350+ * record, and copy one record into the provided buffer.
2351+ *
2352+ * Consecutive calls will return the next available record moving
2353+ * towards the end of the buffer with the youngest messages.
2354+ *
2355+ * A return value of FALSE indicates that there are no more records to
2356+ * read.
2357+ */
2358+bool kmsg_dump_get_line(struct kmsg_dumper *dumper, bool syslog,
2359+ char *line, size_t size, size_t *len)
2360+{
2361+ unsigned long flags;
2362+ struct log *msg;
2363+ size_t l = 0;
2364+ bool ret = false;
2365+
2366+ if (!dumper->active)
2367+ goto out;
23202368
23212369 raw_spin_lock_irqsave(&logbuf_lock, flags);
2322− if (syslog_seq < log_first_seq)
2323− idx = syslog_idx;
2324− else
2325− idx = log_first_idx;
2370+ if (dumper->cur_seq < log_first_seq) {
2371+ /* messages are gone, move to first available one */
2372+ dumper->cur_seq = log_first_seq;
2373+ dumper->cur_idx = log_first_idx;
2374+ }
23262375
2327− if (idx > log_next_idx) {
2328− s1 = log_buf;
2329− l1 = log_next_idx;
2376+ /* last entry */
2377+ if (dumper->cur_seq >= log_next_seq) {
2378+ raw_spin_unlock_irqrestore(&logbuf_lock, flags);
2379+ goto out;
2380+ }
23302381
2331− s2 = log_buf + idx;
2332− l2 = log_buf_len - idx;
2333− } else {
2334− s1 = "";
2335− l1 = 0;
2382+ msg = log_from_idx(dumper->cur_idx);
2383+ l = msg_print_text(msg, syslog,
2384+ line, size);
2385+
2386+ dumper->cur_idx = log_next(dumper->cur_idx);
2387+ dumper->cur_seq++;
2388+ ret = true;
2389+ raw_spin_unlock_irqrestore(&logbuf_lock, flags);
2390+out:
2391+ if (len)
2392+ *len = l;
2393+ return ret;
2394+}
2395+EXPORT_SYMBOL_GPL(kmsg_dump_get_line);
2396+
2397+/**
2398+ * kmsg_dump_get_buffer - copy kmsg log lines
2399+ * @dumper: registered kmsg dumper
2400+ * @syslog: include the "<4>" prefixes
2401+ * @line: buffer to copy the line to
2402+ * @size: maximum size of the buffer
2403+ * @len: length of line placed into buffer
2404+ *
2405+ * Start at the end of the kmsg buffer and fill the provided buffer
2406+ * with as many of the the *youngest* kmsg records that fit into it.
2407+ * If the buffer is large enough, all available kmsg records will be
2408+ * copied with a single call.
2409+ *
2410+ * Consecutive calls will fill the buffer with the next block of
2411+ * available older records, not including the earlier retrieved ones.
2412+ *
2413+ * A return value of FALSE indicates that there are no more records to
2414+ * read.
2415+ */
2416+bool kmsg_dump_get_buffer(struct kmsg_dumper *dumper, bool syslog,
2417+ char *buf, size_t size, size_t *len)
2418+{
2419+ unsigned long flags;
2420+ u64 seq;
2421+ u32 idx;
2422+ u64 next_seq;
2423+ u32 next_idx;
2424+ size_t l = 0;
2425+ bool ret = false;
2426+
2427+ if (!dumper->active)
2428+ goto out;
2429+
2430+ raw_spin_lock_irqsave(&logbuf_lock, flags);
2431+ if (dumper->cur_seq < log_first_seq) {
2432+ /* messages are gone, move to first available one */
2433+ dumper->cur_seq = log_first_seq;
2434+ dumper->cur_idx = log_first_idx;
2435+ }
2436+
2437+ /* last entry */
2438+ if (dumper->cur_seq >= dumper->next_seq) {
2439+ raw_spin_unlock_irqrestore(&logbuf_lock, flags);
2440+ goto out;
2441+ }
2442+
2443+ /* calculate length of entire buffer */
2444+ seq = dumper->cur_seq;
2445+ idx = dumper->cur_idx;
2446+ while (seq < dumper->next_seq) {
2447+ struct log *msg = log_from_idx(idx);
2448+
2449+ l += msg_print_text(msg, true, NULL, 0);
2450+ idx = log_next(idx);
2451+ seq++;
2452+ }
2453+
2454+ /* move first record forward until length fits into the buffer */
2455+ seq = dumper->cur_seq;
2456+ idx = dumper->cur_idx;
2457+ while (l > size && seq < dumper->next_seq) {
2458+ struct log *msg = log_from_idx(idx);
23362459
2337− s2 = log_buf + idx;
2338− l2 = log_next_idx - idx;
2460+ l -= msg_print_text(msg, true, NULL, 0);
2461+ idx = log_next(idx);
2462+ seq++;
23392463 }
2464+
2465+ /* last message in next interation */
2466+ next_seq = seq;
2467+ next_idx = idx;
2468+
2469+ l = 0;
2470+ while (seq < dumper->next_seq) {
2471+ struct log *msg = log_from_idx(idx);
2472+
2473+ l += msg_print_text(msg, syslog,
2474+ buf + l, size - l);
2475+
2476+ idx = log_next(idx);
2477+ seq++;
2478+ }
2479+
2480+ dumper->next_seq = next_seq;
2481+ dumper->next_idx = next_idx;
2482+ ret = true;
23402483 raw_spin_unlock_irqrestore(&logbuf_lock, flags);
2484+out:
2485+ if (len)
2486+ *len = l;
2487+ return ret;
2488+}
2489+EXPORT_SYMBOL_GPL(kmsg_dump_get_buffer);
23412490
2342− rcu_read_lock();
2343− list_for_each_entry_rcu(dumper, &dump_list, list)
2344− dumper->dump(dumper, reason, s1, l1, s2, l2);
2345− rcu_read_unlock();
2491+/**
2492+ * kmsg_dump_rewind - reset the interator
2493+ * @dumper: registered kmsg dumper
2494+ *
2495+ * Reset the dumper's iterator so that kmsg_dump_get_line() and
2496+ * kmsg_dump_get_buffer() can be called again and used multiple
2497+ * times within the same dumper.dump() callback.
2498+ */
2499+void kmsg_dump_rewind(struct kmsg_dumper *dumper)
2500+{
2501+ unsigned long flags;
2502+
2503+ raw_spin_lock_irqsave(&logbuf_lock, flags);
2504+ dumper->cur_seq = clear_seq;
2505+ dumper->cur_idx = clear_idx;
2506+ dumper->next_seq = log_next_seq;
2507+ dumper->next_idx = log_next_idx;
2508+ raw_spin_unlock_irqrestore(&logbuf_lock, flags);
23462509 }
2510+EXPORT_SYMBOL_GPL(kmsg_dump_rewind);
23472511 #endif

Keyboard shortcuts

General

Show keyboard shortcuts
?
Focus the current search
/

Issues and pull requests

Open filters
f

Issues, pull requests and Inbox

Select next item
j↓
Select previous item
k↑
Open selected item
Enter
Dismiss filters or clear selection
Esc

Repository code

Go to file
t