Skip to contentSkip to conversation

trace: correct start_index in find_next

PATCH In review Qiu, PeiyangX 3 participants 4 messages Dec 31, 2015 – Jan 7, 2016 Tracing

lore
Share & tools
lore
#0 lore raw

PATCH 1/1 trace: correct start_index in find_next

From: Qiu Peiyang <[email protected]>

When we do cat /sys/kernel/debug/tracing/printk_formats, we hit kernel panic at t_show.

general protection fault: 0000 [#1] PREEMPT SMP 
CPU: 0 PID: 2957 Comm: sh Tainted: G W  O 3.14.55-x86_64-01062-gd4acdc7 #2
RIP: 0010:[<ffffffff811375b2>] 
 [<ffffffff811375b2>] t_show+0x22/0xe0
RSP: 0000:ffff88002b4ebe80  EFLAGS: 00010246
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000004
RDX: 0000000000000004 RSI: ffffffff81fd26a6 RDI: ffff880032f9f7b1
RBP: ffff88002b4ebe98 R08: 0000000000001000 R09: 000000000000ffec
R10: 0000000000000000 R11: 000000000000000f R12: ffff880004d9b6c0
R13: 7365725f6d706400 R14: ffff880004d9b6c0 R15: ffffffff82020570
FS:  0000000000000000(0000) GS:ffff88003aa00000(0063) knlGS:00000000f776bc40
CS:  0010 DS: 002b ES: 002b CR0: 0000000080050033
CR2: 00000000f6c02ff0 CR3: 000000002c2b3000 CR4: 00000000001007f0
Call Trace:
 [<ffffffff811dc076>] seq_read+0x2f6/0x3e0
 [<ffffffff811b749b>] vfs_read+0x9b/0x160
 [<ffffffff811b7f69>] SyS_read+0x49/0xb0
 [<ffffffff81a3a4b9>] ia32_do_call+0x13/0x13
 ---[ end trace 5bd9eb630614861e ]---
Kernel panic - not syncing: Fatal exception

When the first time find_next calls find_next_mod_format, it should iterate the trace_bprintk_fmt_list to find the first print format of the module. However in current code, start_index is smaller than *pos at first, and code will not iterate the list. Latter container_of will get the wrong address with former v, which will cause mod_fmt be a meaningless object and so is the returned mod_fmt->fmt.

This patch will fix it by correcting the start_index. After fixed, when the first time calls find_next_mod_format, start_index will be equal to *pos, and code will iterate the trace_bprintk_fmt_list to get the right module printk format, so is the returned mod_fmt->fmt.

---
 kernel/trace/trace_printk.c | 1 +
 1 file changed, 1 insertion(+)
kernel/trace/trace_printk.c +1 -0
index 1c2b285..64f0a26 100644
@@ -273,6 +273,7 @@ static const char **find_next(void *v, loff_t *pos)
 	if (*pos < last_index + start_index)
 		return __start___tracepoint_str + (*pos - last_index);
 
+	start_index += last_index;
 	return find_next_mod_format(start_index, v, fmt, pos);
 }
 
Signature · 1 line
1.9.1
#1 lore raw
Quoted 48 lines · PeiyangX

From: Qiu Peiyang <[email protected]>

When we do cat /sys/kernel/debug/tracing/printk_formats, we hit kernel panic at t_show.

general protection fault: 0000 [#1] PREEMPT SMP 
CPU: 0 PID: 2957 Comm: sh Tainted: G W  O 3.14.55-x86_64-01062-gd4acdc7 #2
RIP: 0010:[<ffffffff811375b2>] 
 [<ffffffff811375b2>] t_show+0x22/0xe0
RSP: 0000:ffff88002b4ebe80  EFLAGS: 00010246
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000004
RDX: 0000000000000004 RSI: ffffffff81fd26a6 RDI: ffff880032f9f7b1
RBP: ffff88002b4ebe98 R08: 0000000000001000 R09: 000000000000ffec
R10: 0000000000000000 R11: 000000000000000f R12: ffff880004d9b6c0
R13: 7365725f6d706400 R14: ffff880004d9b6c0 R15: ffffffff82020570
FS:  0000000000000000(0000) GS:ffff88003aa00000(0063) knlGS:00000000f776bc40
CS:  0010 DS: 002b ES: 002b CR0: 0000000080050033
CR2: 00000000f6c02ff0 CR3: 000000002c2b3000 CR4: 00000000001007f0
Call Trace:
 [<ffffffff811dc076>] seq_read+0x2f6/0x3e0
 [<ffffffff811b749b>] vfs_read+0x9b/0x160
 [<ffffffff811b7f69>] SyS_read+0x49/0xb0
 [<ffffffff81a3a4b9>] ia32_do_call+0x13/0x13
 ---[ end trace 5bd9eb630614861e ]---
Kernel panic - not syncing: Fatal exception

When the first time find_next calls find_next_mod_format, it should iterate the trace_bprintk_fmt_list to find the first print format of the module. However in current code, start_index is smaller than *pos at first, and code will not iterate the list. Latter container_of will get the wrong address with former v, which will cause mod_fmt be a meaningless object and so is the returned mod_fmt->fmt.

This patch will fix it by correcting the start_index. After fixed, when the first time calls find_next_mod_format, start_index will be equal to *pos, and code will iterate the trace_bprintk_fmt_list to get the right module printk format, so is the returned mod_fmt->fmt.

---
 kernel/trace/trace_printk.c | 1 +
 1 file changed, 1 insertion(+)
kernel/trace/trace_printk.c +0 -0
index 1c2b285..64f0a26 100644

kernel/trace/trace_printk.c static const char **find_next(void *v, loff_t *pos) · line 278

Quoted 6 lines
kernel/trace/trace_printk.c +1 -0
@@ -273,6 +273,7 @@ static const char **find_next(void *v, loff_t *pos)
 	if (*pos < last_index + start_index)
 		return __start___tracepoint_str + (*pos - last_index);
 
+	start_index += last_index;
 	return find_next_mod_format(start_index, v, fmt, pos);
 }

Rusty, Steven,

How is this patch? It fixes a kernel panic.

Yanmin

maintainer
#2 lore raw
Quoted 2 lines · Yanmin

How is this patch? It fixes a kernel panic.

Linus already pulled it. It's also marked for stable. See commit:
f36d1be2930ede0a1947686e1126ffda5d5ee1bb in Linus's tree.

I renamed the subject slightly to:

"tracing: Fix setting of start_index in find_next()"

-- Steve

#3 lore raw
Quoted 12 lines · Steven Rostedt
Quoted 2 lines · Yanmin

How is this patch? It fixes a kernel panic.

Linus already pulled it. It's also marked for stable. See commit:
f36d1be2930ede0a1947686e1126ffda5d5ee1bb in Linus's tree.

I renamed the subject slightly to:

"tracing: Fix setting of start_index in find_next()"

Thanks as usual.