]>
Commit | Line | Data |
---|---|---|
bf9ffb20 GKH |
1 | From 021de3d904b88b1771a3a2cfc5b75023c391e646 Mon Sep 17 00:00:00 2001 |
2 | From: "Steven Rostedt (Red Hat)" <rostedt@goodmis.org> | |
3 | Date: Wed, 6 Aug 2014 15:36:31 -0400 | |
4 | Subject: ring-buffer: Up rb_iter_peek() loop count to 3 | |
5 | ||
6 | From: "Steven Rostedt (Red Hat)" <rostedt@goodmis.org> | |
7 | ||
8 | commit 021de3d904b88b1771a3a2cfc5b75023c391e646 upstream. | |
9 | ||
10 | After writting a test to try to trigger the bug that caused the | |
11 | ring buffer iterator to become corrupted, I hit another bug: | |
12 | ||
13 | WARNING: CPU: 1 PID: 5281 at kernel/trace/ring_buffer.c:3766 rb_iter_peek+0x113/0x238() | |
14 | Modules linked in: ipt_MASQUERADE sunrpc [...] | |
15 | CPU: 1 PID: 5281 Comm: grep Tainted: G W 3.16.0-rc3-test+ #143 | |
16 | Hardware name: To Be Filled By O.E.M. To Be Filled By O.E.M./To be filled by O.E.M., BIOS SDBLI944.86P 05/08/2007 | |
17 | 0000000000000000 ffffffff81809a80 ffffffff81503fb0 0000000000000000 | |
18 | ffffffff81040ca1 ffff8800796d6010 ffffffff810c138d ffff8800796d6010 | |
19 | ffff880077438c80 ffff8800796d6010 ffff88007abbe600 0000000000000003 | |
20 | Call Trace: | |
21 | [<ffffffff81503fb0>] ? dump_stack+0x4a/0x75 | |
22 | [<ffffffff81040ca1>] ? warn_slowpath_common+0x7e/0x97 | |
23 | [<ffffffff810c138d>] ? rb_iter_peek+0x113/0x238 | |
24 | [<ffffffff810c138d>] ? rb_iter_peek+0x113/0x238 | |
25 | [<ffffffff810c14df>] ? ring_buffer_iter_peek+0x2d/0x5c | |
26 | [<ffffffff810c6f73>] ? tracing_iter_reset+0x6e/0x96 | |
27 | [<ffffffff810c74a3>] ? s_start+0xd7/0x17b | |
28 | [<ffffffff8112b13e>] ? kmem_cache_alloc_trace+0xda/0xea | |
29 | [<ffffffff8114cf94>] ? seq_read+0x148/0x361 | |
30 | [<ffffffff81132d98>] ? vfs_read+0x93/0xf1 | |
31 | [<ffffffff81132f1b>] ? SyS_read+0x60/0x8e | |
32 | [<ffffffff8150bf9f>] ? tracesys+0xdd/0xe2 | |
33 | ||
34 | Debugging this bug, which triggers when the rb_iter_peek() loops too | |
35 | many times (more than 2 times), I discovered there's a case that can | |
36 | cause that function to legitimately loop 3 times! | |
37 | ||
38 | rb_iter_peek() is different than rb_buffer_peek() as the rb_buffer_peek() | |
39 | only deals with the reader page (it's for consuming reads). The | |
40 | rb_iter_peek() is for traversing the buffer without consuming it, and as | |
41 | such, it can loop for one more reason. That is, if we hit the end of | |
42 | the reader page or any page, it will go to the next page and try again. | |
43 | ||
44 | That is, we have this: | |
45 | ||
46 | 1. iter->head > iter->head_page->page->commit | |
47 | (rb_inc_iter() which moves the iter to the next page) | |
48 | try again | |
49 | ||
50 | 2. event = rb_iter_head_event() | |
51 | event->type_len == RINGBUF_TYPE_TIME_EXTEND | |
52 | rb_advance_iter() | |
53 | try again | |
54 | ||
55 | 3. read the event. | |
56 | ||
57 | But we never get to 3, because the count is greater than 2 and we | |
58 | cause the WARNING and return NULL. | |
59 | ||
60 | Up the counter to 3. | |
61 | ||
62 | Fixes: 69d1b839f7ee "ring-buffer: Bind time extend and data events together" | |
63 | Signed-off-by: Steven Rostedt <rostedt@goodmis.org> | |
64 | Signed-off-by: Greg Kroah-Hartman <gregkh@linuxfoundation.org> | |
65 | ||
66 | --- | |
67 | kernel/trace/ring_buffer.c | 14 ++++++++------ | |
68 | 1 file changed, 8 insertions(+), 6 deletions(-) | |
69 | ||
70 | --- a/kernel/trace/ring_buffer.c | |
71 | +++ b/kernel/trace/ring_buffer.c | |
72 | @@ -1984,7 +1984,7 @@ rb_add_time_stamp(struct ring_buffer_eve | |
73 | ||
74 | /** | |
75 | * rb_update_event - update event type and data | |
76 | - * @event: the even to update | |
77 | + * @event: the event to update | |
78 | * @type: the type of event | |
79 | * @length: the size of the event field in the ring buffer | |
80 | * | |
81 | @@ -3759,12 +3759,14 @@ rb_iter_peek(struct ring_buffer_iter *it | |
82 | return NULL; | |
83 | ||
84 | /* | |
85 | - * We repeat when a time extend is encountered. | |
86 | - * Since the time extend is always attached to a data event, | |
87 | - * we should never loop more than once. | |
88 | - * (We never hit the following condition more than twice). | |
89 | + * We repeat when a time extend is encountered or we hit | |
90 | + * the end of the page. Since the time extend is always attached | |
91 | + * to a data event, we should never loop more than three times. | |
92 | + * Once for going to next page, once on time extend, and | |
93 | + * finally once to get the event. | |
94 | + * (We never hit the following condition more than thrice). | |
95 | */ | |
96 | - if (RB_WARN_ON(cpu_buffer, ++nr_loops > 2)) | |
97 | + if (RB_WARN_ON(cpu_buffer, ++nr_loops > 3)) | |
98 | return NULL; | |
99 | ||
100 | if (rb_per_cpu_empty(cpu_buffer)) |