* ptrace: gpf in syscall_trace_enter
@ 2014-05-07 0:36 Sasha Levin
2014-05-07 2:50 ` Sasha Levin
2014-05-07 14:00 ` Oleg Nesterov
0 siblings, 2 replies; 12+ messages in thread
From: Sasha Levin @ 2014-05-07 0:36 UTC (permalink / raw)
To: roland, Oleg Nesterov; +Cc: LKML, Dave Jones
Hi all,
While fuzzing with trinity inside a KVM tools guest running the latest -next
kernel I've stumbled on the following spew:
[ 3029.100936] general protection fault: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC
[ 3029.102198] Dumping ftrace buffer:
[ 3029.102928] (ftrace buffer empty)
[ 3029.103644] Modules linked in:
[ 3029.104732] CPU: 16 PID: 4959 Comm: sleep Tainted: G B 3.15.0-rc4-next-20140506-sasha-00021-gc164334-dirty #447
[ 3029.108662] task: ffff8805472f8000 ti: ffff880547e3e000 task.ti: ffff880547e3e000
[ 3029.109900] RIP: syscall_trace_enter (include/trace/events/syscalls.h:16 arch/x86/kernel/ptrace.c:1488)
[ 3029.110064] RSP: 0018:ffff880547e3ff28 EFLAGS: 00010286
[ 3029.110064] RAX: 0000000000000000 RBX: ffff880547e3ff58 RCX: 0000000000000001
[ 3029.110064] RDX: 000000000000000c RSI: ffff880547e3ff58 RDI: 6b6b6b6b6b6b6b6b
[ 3029.110064] RBP: ffff880547e3ff48 R08: 0000000000000000 R09: 0000000000000001
[ 3029.110064] R10: 0000000000000000 R11: 0000000000000000 R12: 000000000000000c
[ 3029.110064] R13: 0000000000000000 R14: ffff880039583d50 R15: 0000000000001000
[ 3029.110064] FS: 0000000000000000(0000) GS:ffff8803d6e00000(0000) knlGS:0000000000000000
[ 3029.110064] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 3029.110064] CR2: 00007fe08b205130 CR3: 000000061d271000 CR4: 00000000000006a0
[ 3029.110064] DR0: 00000000006df000 DR1: 0000000000000000 DR2: 0000000000000000
[ 3029.110064] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000600
[ 3029.110064] Stack:
[ 3029.110064] 0000000000400040 0000000000000009 00007fffe95ab4b9 0000000000000000
[ 3029.110064] 00007fe08afe64e0 ffffffffaa585625 0000000000001000 0000000000000000
[ 3029.110064] 00007fffe95ab4b9 0000000000000009 00007fe08afe64e0 0000000000400040
[ 3029.110064] Call Trace:
[ 3029.110064] tracesys (arch/x86/kernel/entry_64.S:736)
[ 3029.110064] Code: c6 05 e0 9f f0 05 01 e8 3d 30 14 00 4d 85 f6 75 10 65 ff 0c 25 a0 da 00 00 0f 84 ca 00 00 00 eb 19 49 8b 7e 08 4c 89 e2 48 89 de <41> ff 16 49 83 c6 10 49 83 3e 00 75 e9 eb d7 4c 8b 63 78 0f 1f
[ 3029.110064] RIP syscall_trace_enter (include/trace/events/syscalls.h:16 arch/x86/kernel/ptrace.c:1488)
[ 3029.110064] RSP <ffff880547e3ff28>
Thanks,
Sasha
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: ptrace: gpf in syscall_trace_enter
2014-05-07 0:36 ptrace: gpf in syscall_trace_enter Sasha Levin
@ 2014-05-07 2:50 ` Sasha Levin
2014-05-07 14:04 ` Oleg Nesterov
2014-05-07 14:00 ` Oleg Nesterov
1 sibling, 1 reply; 12+ messages in thread
From: Sasha Levin @ 2014-05-07 2:50 UTC (permalink / raw)
To: roland, Oleg Nesterov; +Cc: LKML, Dave Jones
On 05/06/2014 08:36 PM, Sasha Levin wrote:
> Hi all,
>
> While fuzzing with trinity inside a KVM tools guest running the latest -next
> kernel I've stumbled on the following spew:
And another similar trace:
[ 6897.628729] general protection fault: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC
[ 6897.629654] Dumping ftrace buffer:
[ 6897.630034] (ftrace buffer empty)
[ 6897.630034] Modules linked in:
[ 6897.630034] CPU: 24 PID: 23736 Comm: trinity-c148 Tainted: G B 3.15.0-rc4-next-20140506-sasha-00021-gc164334-dirty #447
[ 6897.630034] task: ffff88002a870000 ti: ffff88000ef04000 task.ti: ffff88000ef04000
[ 6897.630034] RIP: syscall_trace_leave (include/trace/events/syscalls.h:42 arch/x86/kernel/ptrace.c:1517)
[ 6897.630034] RSP: 0000:ffff88000ef05f20 EFLAGS: 00010286
[ 6897.630034] RAX: 0000000000000000 RBX: ffff88000ef05f58 RCX: 0000000000000001
[ 6897.630034] RDX: fffffffffffffff2 RSI: ffff88000ef05f58 RDI: 6b6b6b6b6b6b6b6b
[ 6897.630034] RBP: ffff88000ef05f40 R08: ffff880218c3c498 R09: 0000000100290024
[ 6897.630034] R10: 0000000000000000 R11: 0000000000000000 R12: ffff8806c5d04630
[ 6897.630034] R13: fffffffffffffff2 R14: 00000000000032e0 R15: 00000000000000af
[ 6897.630034] FS: 00007f5541eec700(0000) GS:ffff880587000000(0000) knlGS:0000000000000000
[ 6897.630034] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 6897.630034] CR2: 00007fff1ac95d78 CR3: 00000000036a0000 CR4: 00000000000006a0
[ 6897.630034] DR0: 00000000006df000 DR1: 0000000000000000 DR2: 0000000000000000
[ 6897.630034] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 00000000000f0602
[ 6897.630034] Stack:
[ 6897.630034] 00007f5541f0e2e0 00000000006e2000 00007f5541f0e2e0 0000000000000094
[ 6897.630034] 0000000000000011 ffffffffb458577f 000000001008feff 00000000000000af
[ 6897.630034] 00000000000032e0 0000000000000094 00007f5541f0e2e0 0000000000000011
[ 6897.630034] Call Trace:
[ 6897.630034] int_check_syscall_exit_work (arch/x86/kernel/entry_64.S:795)
[ 6897.630034] Code: 05 d1 9d f0 05 01 e8 2d 2e 14 00 4d 85 e4 75 10 65 ff 0c 25 a0 da 00 00 0f 84 85 00 00 00 eb 1c 49 8b 7c 24 08 4c 89 ea 48 89 de <41> ff 14 24 49 83 c4 10 49 83 3c 24 00 75 e6 eb d4 0f 1f 40 00
[ 6897.630034] RIP syscall_trace_leave (include/trace/events/syscalls.h:42 arch/x86/kernel/ptrace.c:1517)
[ 6897.630034] RSP <ffff88000ef05f20>
Thanks,
Sasha
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: ptrace: gpf in syscall_trace_enter
2014-05-07 0:36 ptrace: gpf in syscall_trace_enter Sasha Levin
2014-05-07 2:50 ` Sasha Levin
@ 2014-05-07 14:00 ` Oleg Nesterov
1 sibling, 0 replies; 12+ messages in thread
From: Oleg Nesterov @ 2014-05-07 14:00 UTC (permalink / raw)
To: Sasha Levin, Steven Rostedt; +Cc: roland, LKML, Dave Jones
Hi,
On 05/06, Sasha Levin wrote:
>
> Hi all,
>
> While fuzzing with trinity inside a KVM tools guest running the latest -next
> kernel I've stumbled on the following spew:
This is not ptrace ;)
At first glance, tracepoint->funcs corruption. Add Steven.
> [ 3029.100936] general protection fault: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC
> [ 3029.102198] Dumping ftrace buffer:
> [ 3029.102928] (ftrace buffer empty)
> [ 3029.103644] Modules linked in:
> [ 3029.104732] CPU: 16 PID: 4959 Comm: sleep Tainted: G B 3.15.0-rc4-next-20140506-sasha-00021-gc164334-dirty #447
> [ 3029.108662] task: ffff8805472f8000 ti: ffff880547e3e000 task.ti: ffff880547e3e000
> [ 3029.109900] RIP: syscall_trace_enter (include/trace/events/syscalls.h:16 arch/x86/kernel/ptrace.c:1488)
> [ 3029.110064] RSP: 0018:ffff880547e3ff28 EFLAGS: 00010286
> [ 3029.110064] RAX: 0000000000000000 RBX: ffff880547e3ff58 RCX: 0000000000000001
> [ 3029.110064] RDX: 000000000000000c RSI: ffff880547e3ff58 RDI: 6b6b6b6b6b6b6b6b
> [ 3029.110064] RBP: ffff880547e3ff48 R08: 0000000000000000 R09: 0000000000000001
> [ 3029.110064] R10: 0000000000000000 R11: 0000000000000000 R12: 000000000000000c
> [ 3029.110064] R13: 0000000000000000 R14: ffff880039583d50 R15: 0000000000001000
> [ 3029.110064] FS: 0000000000000000(0000) GS:ffff8803d6e00000(0000) knlGS:0000000000000000
> [ 3029.110064] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
> [ 3029.110064] CR2: 00007fe08b205130 CR3: 000000061d271000 CR4: 00000000000006a0
> [ 3029.110064] DR0: 00000000006df000 DR1: 0000000000000000 DR2: 0000000000000000
> [ 3029.110064] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000600
> [ 3029.110064] Stack:
> [ 3029.110064] 0000000000400040 0000000000000009 00007fffe95ab4b9 0000000000000000
> [ 3029.110064] 00007fe08afe64e0 ffffffffaa585625 0000000000001000 0000000000000000
> [ 3029.110064] 00007fffe95ab4b9 0000000000000009 00007fe08afe64e0 0000000000400040
> [ 3029.110064] Call Trace:
> [ 3029.110064] tracesys (arch/x86/kernel/entry_64.S:736)
> [ 3029.110064] Code: c6 05 e0 9f f0 05 01 e8 3d 30 14 00 4d 85 f6 75 10 65 ff 0c 25 a0 da 00 00 0f 84 ca 00 00 00 eb 19 49 8b 7e 08 4c 89 e2 48 89 de <41> ff 16 49 83 c6 10 49 83 3e 00 75 e9 eb d7 4c 8b 63 78 0f 1f
> [ 3029.110064] RIP syscall_trace_enter (include/trace/events/syscalls.h:16 arch/x86/kernel/ptrace.c:1488)
> [ 3029.110064] RSP <ffff880547e3ff28>
>
>
> Thanks,
> Sasha
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: ptrace: gpf in syscall_trace_enter
2014-05-07 2:50 ` Sasha Levin
@ 2014-05-07 14:04 ` Oleg Nesterov
2014-05-07 14:31 ` Steven Rostedt
2014-05-07 15:49 ` Steven Rostedt
0 siblings, 2 replies; 12+ messages in thread
From: Oleg Nesterov @ 2014-05-07 14:04 UTC (permalink / raw)
To: Sasha Levin, Steven Rostedt; +Cc: roland, LKML, Dave Jones
On 05/06, Sasha Levin wrote:
>
> On 05/06/2014 08:36 PM, Sasha Levin wrote:
> > Hi all,
> >
> > While fuzzing with trinity inside a KVM tools guest running the latest -next
> > kernel I've stumbled on the following spew:
>
> And another similar trace:
Again, this looks like __DO_TRACE() trying to call it_func_ptr->func().
> [ 6897.628729] general protection fault: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC
> [ 6897.629654] Dumping ftrace buffer:
> [ 6897.630034] (ftrace buffer empty)
> [ 6897.630034] Modules linked in:
> [ 6897.630034] CPU: 24 PID: 23736 Comm: trinity-c148 Tainted: G B 3.15.0-rc4-next-20140506-sasha-00021-gc164334-dirty #447
> [ 6897.630034] task: ffff88002a870000 ti: ffff88000ef04000 task.ti: ffff88000ef04000
> [ 6897.630034] RIP: syscall_trace_leave (include/trace/events/syscalls.h:42 arch/x86/kernel/ptrace.c:1517)
> [ 6897.630034] RSP: 0000:ffff88000ef05f20 EFLAGS: 00010286
> [ 6897.630034] RAX: 0000000000000000 RBX: ffff88000ef05f58 RCX: 0000000000000001
> [ 6897.630034] RDX: fffffffffffffff2 RSI: ffff88000ef05f58 RDI: 6b6b6b6b6b6b6b6b
> [ 6897.630034] RBP: ffff88000ef05f40 R08: ffff880218c3c498 R09: 0000000100290024
> [ 6897.630034] R10: 0000000000000000 R11: 0000000000000000 R12: ffff8806c5d04630
> [ 6897.630034] R13: fffffffffffffff2 R14: 00000000000032e0 R15: 00000000000000af
> [ 6897.630034] FS: 00007f5541eec700(0000) GS:ffff880587000000(0000) knlGS:0000000000000000
> [ 6897.630034] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
> [ 6897.630034] CR2: 00007fff1ac95d78 CR3: 00000000036a0000 CR4: 00000000000006a0
> [ 6897.630034] DR0: 00000000006df000 DR1: 0000000000000000 DR2: 0000000000000000
> [ 6897.630034] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 00000000000f0602
> [ 6897.630034] Stack:
> [ 6897.630034] 00007f5541f0e2e0 00000000006e2000 00007f5541f0e2e0 0000000000000094
> [ 6897.630034] 0000000000000011 ffffffffb458577f 000000001008feff 00000000000000af
> [ 6897.630034] 00000000000032e0 0000000000000094 00007f5541f0e2e0 0000000000000011
> [ 6897.630034] Call Trace:
> [ 6897.630034] int_check_syscall_exit_work (arch/x86/kernel/entry_64.S:795)
> [ 6897.630034] Code: 05 d1 9d f0 05 01 e8 2d 2e 14 00 4d 85 e4 75 10 65 ff 0c 25 a0 da 00 00 0f 84 85 00 00 00 eb 1c 49 8b 7c 24 08 4c 89 ea 48 89 de <41> ff 14 24 49 83 c4 10 49 83 3c 24 00 75 e6 eb d4 0f 1f 40 00
> [ 6897.630034] RIP syscall_trace_leave (include/trace/events/syscalls.h:42 arch/x86/kernel/ptrace.c:1517)
> [ 6897.630034] RSP <ffff88000ef05f20>
>
>
> Thanks,
> Sasha
>
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: ptrace: gpf in syscall_trace_enter
2014-05-07 14:04 ` Oleg Nesterov
@ 2014-05-07 14:31 ` Steven Rostedt
2014-05-07 15:23 ` Sasha Levin
2014-05-07 15:49 ` Steven Rostedt
1 sibling, 1 reply; 12+ messages in thread
From: Steven Rostedt @ 2014-05-07 14:31 UTC (permalink / raw)
To: Oleg Nesterov; +Cc: Sasha Levin, roland, LKML, Dave Jones
On Wed, 7 May 2014 16:04:22 +0200
Oleg Nesterov <oleg@redhat.com> wrote:
> On 05/06, Sasha Levin wrote:
> >
> > On 05/06/2014 08:36 PM, Sasha Levin wrote:
> > > Hi all,
> > >
> > > While fuzzing with trinity inside a KVM tools guest running the latest -next
> > > kernel I've stumbled on the following spew:
> >
> > And another similar trace:
>
> Again, this looks like __DO_TRACE() trying to call it_func_ptr->func().
Really? Can I see an objdump of the location of the crash. Preferably
the entire function.
Thanks!
-- Steve
>
> > [ 6897.628729] general protection fault: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC
> > [ 6897.629654] Dumping ftrace buffer:
> > [ 6897.630034] (ftrace buffer empty)
> > [ 6897.630034] Modules linked in:
> > [ 6897.630034] CPU: 24 PID: 23736 Comm: trinity-c148 Tainted: G B 3.15.0-rc4-next-20140506-sasha-00021-gc164334-dirty #447
> > [ 6897.630034] task: ffff88002a870000 ti: ffff88000ef04000 task.ti: ffff88000ef04000
> > [ 6897.630034] RIP: syscall_trace_leave (include/trace/events/syscalls.h:42 arch/x86/kernel/ptrace.c:1517)
> > [ 6897.630034] RSP: 0000:ffff88000ef05f20 EFLAGS: 00010286
> > [ 6897.630034] RAX: 0000000000000000 RBX: ffff88000ef05f58 RCX: 0000000000000001
> > [ 6897.630034] RDX: fffffffffffffff2 RSI: ffff88000ef05f58 RDI: 6b6b6b6b6b6b6b6b
> > [ 6897.630034] RBP: ffff88000ef05f40 R08: ffff880218c3c498 R09: 0000000100290024
> > [ 6897.630034] R10: 0000000000000000 R11: 0000000000000000 R12: ffff8806c5d04630
> > [ 6897.630034] R13: fffffffffffffff2 R14: 00000000000032e0 R15: 00000000000000af
> > [ 6897.630034] FS: 00007f5541eec700(0000) GS:ffff880587000000(0000) knlGS:0000000000000000
> > [ 6897.630034] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
> > [ 6897.630034] CR2: 00007fff1ac95d78 CR3: 00000000036a0000 CR4: 00000000000006a0
> > [ 6897.630034] DR0: 00000000006df000 DR1: 0000000000000000 DR2: 0000000000000000
> > [ 6897.630034] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 00000000000f0602
> > [ 6897.630034] Stack:
> > [ 6897.630034] 00007f5541f0e2e0 00000000006e2000 00007f5541f0e2e0 0000000000000094
> > [ 6897.630034] 0000000000000011 ffffffffb458577f 000000001008feff 00000000000000af
> > [ 6897.630034] 00000000000032e0 0000000000000094 00007f5541f0e2e0 0000000000000011
> > [ 6897.630034] Call Trace:
> > [ 6897.630034] int_check_syscall_exit_work (arch/x86/kernel/entry_64.S:795)
> > [ 6897.630034] Code: 05 d1 9d f0 05 01 e8 2d 2e 14 00 4d 85 e4 75 10 65 ff 0c 25 a0 da 00 00 0f 84 85 00 00 00 eb 1c 49 8b 7c 24 08 4c 89 ea 48 89 de <41> ff 14 24 49 83 c4 10 49 83 3c 24 00 75 e6 eb d4 0f 1f 40 00
> > [ 6897.630034] RIP syscall_trace_leave (include/trace/events/syscalls.h:42 arch/x86/kernel/ptrace.c:1517)
> > [ 6897.630034] RSP <ffff88000ef05f20>
> >
> >
> > Thanks,
> > Sasha
> >
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: ptrace: gpf in syscall_trace_enter
2014-05-07 14:31 ` Steven Rostedt
@ 2014-05-07 15:23 ` Sasha Levin
2014-05-07 16:06 ` Steven Rostedt
0 siblings, 1 reply; 12+ messages in thread
From: Sasha Levin @ 2014-05-07 15:23 UTC (permalink / raw)
To: Steven Rostedt, Oleg Nesterov; +Cc: roland, LKML, Dave Jones
On 05/07/2014 10:31 AM, Steven Rostedt wrote:
> On Wed, 7 May 2014 16:04:22 +0200
> Oleg Nesterov <oleg@redhat.com> wrote:
>
>> On 05/06, Sasha Levin wrote:
>>>
>>> On 05/06/2014 08:36 PM, Sasha Levin wrote:
>>>> Hi all,
>>>>
>>>> While fuzzing with trinity inside a KVM tools guest running the latest -next
>>>> kernel I've stumbled on the following spew:
>>>
>>> And another similar trace:
>>
>> Again, this looks like __DO_TRACE() trying to call it_func_ptr->func().
>
> Really? Can I see an objdump of the location of the crash. Preferably
> the entire function.
0000000000002740 <syscall_trace_leave>:
2740: e8 00 00 00 00 callq 2745 <syscall_trace_leave+0x5>
2741: R_X86_64_PC32 __fentry__-0x4
2745: 55 push %rbp
2746: 48 89 e5 mov %rsp,%rbp
2749: 48 83 ec 20 sub $0x20,%rsp
274d: 48 89 5d e8 mov %rbx,-0x18(%rbp)
2751: 48 89 fb mov %rdi,%rbx
2754: 4c 89 65 f0 mov %r12,-0x10(%rbp)
2758: 4c 89 6d f8 mov %r13,-0x8(%rbp)
275c: 0f 1f 44 00 00 nopl 0x0(%rax,%rax,1)
2761: 65 48 8b 04 25 00 00 mov %gs:0x0,%rax
2768: 00 00
2766: R_X86_64_32S current_task
276a: 48 83 b8 b8 0b 00 00 cmpq $0x0,0xbb8(%rax)
2771: 00
2772: 74 1c je 2790 <syscall_trace_leave+0x50>
2774: 48 8b 73 50 mov 0x50(%rbx),%rsi
2778: 31 ff xor %edi,%edi
277a: 48 81 fe 00 f0 ff ff cmp $0xfffffffffffff000,%rsi
2781: 40 0f 96 c7 setbe %dil
2785: e8 00 00 00 00 callq 278a <syscall_trace_leave+0x4a>
2786: R_X86_64_PC32 __audit_syscall_exit-0x4
278a: 66 0f 1f 44 00 00 nopw 0x0(%rax,%rax,1)
2790: 65 48 8b 04 25 00 00 mov %gs:0x0,%rax
2797: 00 00
2795: R_X86_64_32S kernel_stack
2799: 48 8b 80 38 e0 ff ff mov -0x1fc8(%rax),%rax
27a0: a9 00 00 00 10 test $0x10000000,%eax
27a5: 74 71 je 2818 <syscall_trace_leave+0xd8>
27a7: 4c 8b 6b 50 mov 0x50(%rbx),%r13
27ab: 0f 1f 44 00 00 nopl 0x0(%rax,%rax,1)
27b0: eb 62 jmp 2814 <syscall_trace_leave+0xd4>
27b2: 80 3d 00 00 00 00 00 cmpb $0x0,0x0(%rip) # 27b9 <syscall_trace_leave+0x79>
27b4: R_X86_64_PC32 .data.unlikely-0x4
27b9: 75 28 jne 27e3 <syscall_trace_leave+0xa3>
27bb: e8 00 00 00 00 callq 27c0 <syscall_trace_leave+0x80>
27bc: R_X86_64_PC32 .text.unlikely-0x4
27c0: 85 c0 test %eax,%eax
27c2: 75 1f jne 27e3 <syscall_trace_leave+0xa3>
27c4: 48 c7 c2 00 00 00 00 mov $0x0,%rdx
27c7: R_X86_64_32S .rodata.str1.8+0x60
27cb: be 3e 00 00 00 mov $0x3e,%esi
27d0: 48 c7 c7 00 00 00 00 mov $0x0,%rdi
27d3: R_X86_64_32S .rodata.str1.8+0x90
27d7: c6 05 00 00 00 00 01 movb $0x1,0x0(%rip) # 27de <syscall_trace_leave+0x9e>
27d9: R_X86_64_PC32 .data.unlikely-0x4
27de: e8 00 00 00 00 callq 27e3 <syscall_trace_leave+0xa3>
27df: R_X86_64_PC32 lockdep_rcu_suspicious-0x4
27e3: 4d 85 e4 test %r12,%r12
27e6: 75 10 jne 27f8 <syscall_trace_leave+0xb8>
27e8: 65 ff 0c 25 00 00 00 decl %gs:0x0
27ef: 00
27ec: R_X86_64_32S __preempt_count
27f0: 0f 84 85 00 00 00 je 287b <syscall_trace_leave+0x13b>
27f6: eb 1c jmp 2814 <syscall_trace_leave+0xd4>
27f8: 49 8b 7c 24 08 mov 0x8(%r12),%rdi
27fd: 4c 89 ea mov %r13,%rdx
2800: 48 89 de mov %rbx,%rsi
2803: 41 ff 14 24 callq *(%r12)
2807: 49 83 c4 10 add $0x10,%r12
280b: 49 83 3c 24 00 cmpq $0x0,(%r12)
2810: 75 e6 jne 27f8 <syscall_trace_leave+0xb8>
2812: eb d4 jmp 27e8 <syscall_trace_leave+0xa8>
2814: 0f 1f 40 00 nopl 0x0(%rax)
2818: 65 48 8b 04 25 00 00 mov %gs:0x0,%rax
281f: 00 00
281d: R_X86_64_32S kernel_stack
2821: 48 8b 90 38 e0 ff ff mov -0x1fc8(%rax),%rdx
2828: 83 e2 10 and $0x10,%edx
282b: 74 5b je 2888 <syscall_trace_leave+0x148>
282d: 48 8b 80 38 e0 ff ff mov -0x1fc8(%rax),%rax
2834: a8 40 test $0x40,%al
2836: 75 50 jne 2888 <syscall_trace_leave+0x148>
2838: be 01 00 00 00 mov $0x1,%esi
283d: 0f 1f 00 nopl (%rax)
2840: 48 89 df mov %rbx,%rdi
2843: e8 f8 fa ff ff callq 2340 <tracehook_report_syscall_exit>
2848: 0f 1f 44 00 00 nopl 0x0(%rax,%rax,1)
284d: eb 56 jmp 28a5 <syscall_trace_leave+0x165>
284f: 90 nop
2850: e8 00 00 00 00 callq 2855 <syscall_trace_leave+0x115>
2851: R_X86_64_PC32 context_tracking_user_exit-0x4
2855: e9 07 ff ff ff jmpq 2761 <syscall_trace_leave+0x21>
285a: 65 ff 04 25 00 00 00 incl %gs:0x0
2861: 00
285e: R_X86_64_32S __preempt_count
2862: 4c 8b 25 00 00 00 00 mov 0x0(%rip),%r12 # 2869 <syscall_trace_leave+0x129>
2865: R_X86_64_PC32 __tracepoint_sys_exit+0x2c
2869: e8 00 00 00 00 callq 286e <syscall_trace_leave+0x12e>
286a: R_X86_64_PC32 debug_lockdep_rcu_enabled-0x4
286e: 85 c0 test %eax,%eax
2870: 0f 85 3c ff ff ff jne 27b2 <syscall_trace_leave+0x72>
2876: e9 68 ff ff ff jmpq 27e3 <syscall_trace_leave+0xa3>
287b: e8 00 00 00 00 callq 2880 <syscall_trace_leave+0x140>
287c: R_X86_64_PC32 ___preempt_schedule_context-0x4
2880: eb 96 jmp 2818 <syscall_trace_leave+0xd8>
2882: 66 0f 1f 44 00 00 nopw 0x0(%rax,%rax,1)
2888: 65 48 8b 04 25 00 00 mov %gs:0x0,%rax
288f: 00 00
288d: R_X86_64_32S kernel_stack
2891: 48 8b 80 38 e0 ff ff mov -0x1fc8(%rax),%rax
2898: 31 f6 xor %esi,%esi
289a: a8 01 test $0x1,%al
289c: 75 a2 jne 2840 <syscall_trace_leave+0x100>
289e: eb a8 jmp 2848 <syscall_trace_leave+0x108>
28a0: e8 00 00 00 00 callq 28a5 <syscall_trace_leave+0x165>
28a1: R_X86_64_PC32 context_tracking_user_enter-0x4
28a5: 48 8b 5d e8 mov -0x18(%rbp),%rbx
28a9: 4c 8b 65 f0 mov -0x10(%rbp),%r12
28ad: 4c 8b 6d f8 mov -0x8(%rbp),%r13
28b1: c9 leaveq
28b2: c3 retq
Thanks,
Sasha
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: ptrace: gpf in syscall_trace_enter
2014-05-07 14:04 ` Oleg Nesterov
2014-05-07 14:31 ` Steven Rostedt
@ 2014-05-07 15:49 ` Steven Rostedt
2014-05-07 15:52 ` Sasha Levin
1 sibling, 1 reply; 12+ messages in thread
From: Steven Rostedt @ 2014-05-07 15:49 UTC (permalink / raw)
To: Oleg Nesterov; +Cc: Sasha Levin, roland, LKML, Dave Jones
On Wed, 7 May 2014 16:04:22 +0200
Oleg Nesterov <oleg@redhat.com> wrote:
> On 05/06, Sasha Levin wrote:
> >
> > On 05/06/2014 08:36 PM, Sasha Levin wrote:
> > > Hi all,
> > >
> > > While fuzzing with trinity inside a KVM tools guest running the latest -next
> > > kernel I've stumbled on the following spew:
> >
> > And another similar trace:
>
> Again, this looks like __DO_TRACE() trying to call it_func_ptr->func().
>
> > [ 6897.628729] general protection fault: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC
> > [ 6897.629654] Dumping ftrace buffer:
> > [ 6897.630034] (ftrace buffer empty)
> > [ 6897.630034] Modules linked in:
> > [ 6897.630034] CPU: 24 PID: 23736 Comm: trinity-c148 Tainted: G B 3.15.0-rc4-next-20140506-sasha-00021-gc164334-dirty #447
> > [ 6897.630034] task: ffff88002a870000 ti: ffff88000ef04000 task.ti: ffff88000ef04000
> > [ 6897.630034] RIP: syscall_trace_leave (include/trace/events/syscalls.h:42 arch/x86/kernel/ptrace.c:1517)
Thanks for sending the objdump, but then I just realized that this dump
doesn't have the actual RIP. It just says syscall_trace_leave, without
even giving me the offset.
As the objdump is just of the object files and not the vmlinux, I would
need the offset from syscall_trace_leave of the RIP.
Thanks,
-- Steve
> > [ 6897.630034] RSP: 0000:ffff88000ef05f20 EFLAGS: 00010286
> > [ 6897.630034] RAX: 0000000000000000 RBX: ffff88000ef05f58 RCX: 0000000000000001
> > [ 6897.630034] RDX: fffffffffffffff2 RSI: ffff88000ef05f58 RDI: 6b6b6b6b6b6b6b6b
> > [ 6897.630034] RBP: ffff88000ef05f40 R08: ffff880218c3c498 R09: 0000000100290024
> > [ 6897.630034] R10: 0000000000000000 R11: 0000000000000000 R12: ffff8806c5d04630
> > [ 6897.630034] R13: fffffffffffffff2 R14: 00000000000032e0 R15: 00000000000000af
> > [ 6897.630034] FS: 00007f5541eec700(0000) GS:ffff880587000000(0000) knlGS:0000000000000000
> > [ 6897.630034] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
> > [ 6897.630034] CR2: 00007fff1ac95d78 CR3: 00000000036a0000 CR4: 00000000000006a0
> > [ 6897.630034] DR0: 00000000006df000 DR1: 0000000000000000 DR2: 0000000000000000
> > [ 6897.630034] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 00000000000f0602
> > [ 6897.630034] Stack:
> > [ 6897.630034] 00007f5541f0e2e0 00000000006e2000 00007f5541f0e2e0 0000000000000094
> > [ 6897.630034] 0000000000000011 ffffffffb458577f 000000001008feff 00000000000000af
> > [ 6897.630034] 00000000000032e0 0000000000000094 00007f5541f0e2e0 0000000000000011
> > [ 6897.630034] Call Trace:
> > [ 6897.630034] int_check_syscall_exit_work (arch/x86/kernel/entry_64.S:795)
> > [ 6897.630034] Code: 05 d1 9d f0 05 01 e8 2d 2e 14 00 4d 85 e4 75 10 65 ff 0c 25 a0 da 00 00 0f 84 85 00 00 00 eb 1c 49 8b 7c 24 08 4c 89 ea 48 89 de <41> ff 14 24 49 83 c4 10 49 83 3c 24 00 75 e6 eb d4 0f 1f 40 00
> > [ 6897.630034] RIP syscall_trace_leave (include/trace/events/syscalls.h:42 arch/x86/kernel/ptrace.c:1517)
> > [ 6897.630034] RSP <ffff88000ef05f20>
> >
> >
> > Thanks,
> > Sasha
> >
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: ptrace: gpf in syscall_trace_enter
2014-05-07 15:49 ` Steven Rostedt
@ 2014-05-07 15:52 ` Sasha Levin
2014-05-07 16:00 ` Steven Rostedt
0 siblings, 1 reply; 12+ messages in thread
From: Sasha Levin @ 2014-05-07 15:52 UTC (permalink / raw)
To: Steven Rostedt, Oleg Nesterov; +Cc: roland, LKML, Dave Jones
On 05/07/2014 11:49 AM, Steven Rostedt wrote:
> On Wed, 7 May 2014 16:04:22 +0200
> Oleg Nesterov <oleg@redhat.com> wrote:
>
>> On 05/06, Sasha Levin wrote:
>>>
>>> On 05/06/2014 08:36 PM, Sasha Levin wrote:
>>>> Hi all,
>>>>
>>>> While fuzzing with trinity inside a KVM tools guest running the latest -next
>>>> kernel I've stumbled on the following spew:
>>>
>>> And another similar trace:
>>
>> Again, this looks like __DO_TRACE() trying to call it_func_ptr->func().
>>
>>> [ 6897.628729] general protection fault: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC
>>> [ 6897.629654] Dumping ftrace buffer:
>>> [ 6897.630034] (ftrace buffer empty)
>>> [ 6897.630034] Modules linked in:
>>> [ 6897.630034] CPU: 24 PID: 23736 Comm: trinity-c148 Tainted: G B 3.15.0-rc4-next-20140506-sasha-00021-gc164334-dirty #447
>>> [ 6897.630034] task: ffff88002a870000 ti: ffff88000ef04000 task.ti: ffff88000ef04000
>>> [ 6897.630034] RIP: syscall_trace_leave (include/trace/events/syscalls.h:42 arch/x86/kernel/ptrace.c:1517)
>
> Thanks for sending the objdump, but then I just realized that this dump
> doesn't have the actual RIP. It just says syscall_trace_leave, without
> even giving me the offset.
>
> As the objdump is just of the object files and not the vmlinux, I would
> need the offset from syscall_trace_leave of the RIP.
2803: 41 ff 14 24 callq *(%r12) <=== Here
2807: 49 83 c4 10 add $0x10,%r12
280b: 49 83 3c 24 00 cmpq $0x0,(%r12)
Thanks,
Sasha
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: ptrace: gpf in syscall_trace_enter
2014-05-07 15:52 ` Sasha Levin
@ 2014-05-07 16:00 ` Steven Rostedt
0 siblings, 0 replies; 12+ messages in thread
From: Steven Rostedt @ 2014-05-07 16:00 UTC (permalink / raw)
To: Sasha Levin; +Cc: Oleg Nesterov, roland, LKML, Dave Jones
On Wed, 07 May 2014 11:52:35 -0400
Sasha Levin <sasha.levin@oracle.com> wrote:
> > As the objdump is just of the object files and not the vmlinux, I would
> > need the offset from syscall_trace_leave of the RIP.
>
> 2803: 41 ff 14 24 callq *(%r12) <=== Here
> 2807: 49 83 c4 10 add $0x10,%r12
> 280b: 49 83 3c 24 00 cmpq $0x0,(%r12)
Yeah, after I sent the email, I figured it out from the
24 08 4c 89 ea 48 89 de <41> ff 14 24 49 83 c4 10 49
Thanks,
-- Steve
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: ptrace: gpf in syscall_trace_enter
2014-05-07 15:23 ` Sasha Levin
@ 2014-05-07 16:06 ` Steven Rostedt
2014-05-07 19:51 ` Andy Lutomirski
2014-05-07 22:55 ` Mathieu Desnoyers
0 siblings, 2 replies; 12+ messages in thread
From: Steven Rostedt @ 2014-05-07 16:06 UTC (permalink / raw)
To: Sasha Levin; +Cc: Oleg Nesterov, roland, LKML, Dave Jones, Mathieu Desnoyers
[ adding Mathieu as well, as this is tracepoint code ]
On Wed, 07 May 2014 11:23:36 -0400
Sasha Levin <sasha.levin@oracle.com> wrote:
> On 05/07/2014 10:31 AM, Steven Rostedt wrote:
> > On Wed, 7 May 2014 16:04:22 +0200
> > Oleg Nesterov <oleg@redhat.com> wrote:
> >
> >> On 05/06, Sasha Levin wrote:
> >>>
> >>> On 05/06/2014 08:36 PM, Sasha Levin wrote:
> >>>> Hi all,
> >>>>
> >>>> While fuzzing with trinity inside a KVM tools guest running the latest -next
> >>>> kernel I've stumbled on the following spew:
> >>>
> >>> And another similar trace:
> >>
> >> Again, this looks like __DO_TRACE() trying to call it_func_ptr->func().
> >
> > Really? Can I see an objdump of the location of the crash. Preferably
> > the entire function.
>
> 0000000000002740 <syscall_trace_leave>:
> 2740: e8 00 00 00 00 callq 2745 <syscall_trace_leave+0x5>
> 2741: R_X86_64_PC32 __fentry__-0x4
> 2745: 55 push %rbp
> 2746: 48 89 e5 mov %rsp,%rbp
> 2749: 48 83 ec 20 sub $0x20,%rsp
> 274d: 48 89 5d e8 mov %rbx,-0x18(%rbp)
> 2751: 48 89 fb mov %rdi,%rbx
> 2754: 4c 89 65 f0 mov %r12,-0x10(%rbp)
> 2758: 4c 89 6d f8 mov %r13,-0x8(%rbp)
> 275c: 0f 1f 44 00 00 nopl 0x0(%rax,%rax,1)
> 2761: 65 48 8b 04 25 00 00 mov %gs:0x0,%rax
> 2768: 00 00
> 2766: R_X86_64_32S current_task
> 276a: 48 83 b8 b8 0b 00 00 cmpq $0x0,0xbb8(%rax)
> 2771: 00
> 2772: 74 1c je 2790 <syscall_trace_leave+0x50>
> 2774: 48 8b 73 50 mov 0x50(%rbx),%rsi
> 2778: 31 ff xor %edi,%edi
> 277a: 48 81 fe 00 f0 ff ff cmp $0xfffffffffffff000,%rsi
> 2781: 40 0f 96 c7 setbe %dil
> 2785: e8 00 00 00 00 callq 278a <syscall_trace_leave+0x4a>
> 2786: R_X86_64_PC32 __audit_syscall_exit-0x4
> 278a: 66 0f 1f 44 00 00 nopw 0x0(%rax,%rax,1)
> 2790: 65 48 8b 04 25 00 00 mov %gs:0x0,%rax
> 2797: 00 00
> 2795: R_X86_64_32S kernel_stack
> 2799: 48 8b 80 38 e0 ff ff mov -0x1fc8(%rax),%rax
> 27a0: a9 00 00 00 10 test $0x10000000,%eax
> 27a5: 74 71 je 2818 <syscall_trace_leave+0xd8>
> 27a7: 4c 8b 6b 50 mov 0x50(%rbx),%r13
> 27ab: 0f 1f 44 00 00 nopl 0x0(%rax,%rax,1)
Here's the static_key branch
> 27b0: eb 62 jmp 2814 <syscall_trace_leave+0xd4>
> 27b2: 80 3d 00 00 00 00 00 cmpb $0x0,0x0(%rip) # 27b9 <syscall_trace_leave+0x79>
> 27b4: R_X86_64_PC32 .data.unlikely-0x4
> 27b9: 75 28 jne 27e3 <syscall_trace_leave+0xa3>
> 27bb: e8 00 00 00 00 callq 27c0 <syscall_trace_leave+0x80>
> 27bc: R_X86_64_PC32 .text.unlikely-0x4
Interesting that we have a "callq" to the next instruction.
> 27c0: 85 c0 test %eax,%eax
> 27c2: 75 1f jne 27e3 <syscall_trace_leave+0xa3>
> 27c4: 48 c7 c2 00 00 00 00 mov $0x0,%rdx
> 27c7: R_X86_64_32S .rodata.str1.8+0x60
> 27cb: be 3e 00 00 00 mov $0x3e,%esi
> 27d0: 48 c7 c7 00 00 00 00 mov $0x0,%rdi
> 27d3: R_X86_64_32S .rodata.str1.8+0x90
> 27d7: c6 05 00 00 00 00 01 movb $0x1,0x0(%rip) # 27de <syscall_trace_leave+0x9e>
> 27d9: R_X86_64_PC32 .data.unlikely-0x4
> 27de: e8 00 00 00 00 callq 27e3 <syscall_trace_leave+0xa3>
> 27df: R_X86_64_PC32 lockdep_rcu_suspicious-0x4
OK, rcu debugging is on. Not really a factor, just making notes.
> 27e3: 4d 85 e4 test %r12,%r12
%r12 is the it_func_ptr
> 27e6: 75 10 jne 27f8 <syscall_trace_leave+0xb8>
> 27e8: 65 ff 0c 25 00 00 00 decl %gs:0x0
> 27ef: 00
> 27ec: R_X86_64_32S __preempt_count
> 27f0: 0f 84 85 00 00 00 je 287b <syscall_trace_leave+0x13b>
> 27f6: eb 1c jmp 2814 <syscall_trace_leave+0xd4>
> 27f8: 49 8b 7c 24 08 mov 0x8(%r12),%rdi
> 27fd: 4c 89 ea mov %r13,%rdx
> 2800: 48 89 de mov %rbx,%rsi
> 2803: 41 ff 14 24 callq *(%r12)
As I stated, I didn't need the offset that I asked for, but the
machine code had the information I needed:
24 08 4c 89 ea 48 89 de <41> ff 14 24 49 83 c4 10 49
Which matches 2803.
>From your dump:
R10: 0000000000000000 R11: 0000000000000000 R12: 000000000000000c
Yeah, that's a bad pointer.
OK, for some reason, funcs got 0xc?
-- Steve
> 2807: 49 83 c4 10 add $0x10,%r12
> 280b: 49 83 3c 24 00 cmpq $0x0,(%r12)
> 2810: 75 e6 jne 27f8 <syscall_trace_leave+0xb8>
> 2812: eb d4 jmp 27e8 <syscall_trace_leave+0xa8>
> 2814: 0f 1f 40 00 nopl 0x0(%rax)
> 2818: 65 48 8b 04 25 00 00 mov %gs:0x0,%rax
> 281f: 00 00
> 281d: R_X86_64_32S kernel_stack
> 2821: 48 8b 90 38 e0 ff ff mov -0x1fc8(%rax),%rdx
> 2828: 83 e2 10 and $0x10,%edx
> 282b: 74 5b je 2888 <syscall_trace_leave+0x148>
> 282d: 48 8b 80 38 e0 ff ff mov -0x1fc8(%rax),%rax
> 2834: a8 40 test $0x40,%al
> 2836: 75 50 jne 2888 <syscall_trace_leave+0x148>
> 2838: be 01 00 00 00 mov $0x1,%esi
> 283d: 0f 1f 00 nopl (%rax)
> 2840: 48 89 df mov %rbx,%rdi
> 2843: e8 f8 fa ff ff callq 2340 <tracehook_report_syscall_exit>
> 2848: 0f 1f 44 00 00 nopl 0x0(%rax,%rax,1)
> 284d: eb 56 jmp 28a5 <syscall_trace_leave+0x165>
> 284f: 90 nop
> 2850: e8 00 00 00 00 callq 2855 <syscall_trace_leave+0x115>
> 2851: R_X86_64_PC32 context_tracking_user_exit-0x4
> 2855: e9 07 ff ff ff jmpq 2761 <syscall_trace_leave+0x21>
> 285a: 65 ff 04 25 00 00 00 incl %gs:0x0
> 2861: 00
> 285e: R_X86_64_32S __preempt_count
> 2862: 4c 8b 25 00 00 00 00 mov 0x0(%rip),%r12 # 2869 <syscall_trace_leave+0x129>
> 2865: R_X86_64_PC32 __tracepoint_sys_exit+0x2c
> 2869: e8 00 00 00 00 callq 286e <syscall_trace_leave+0x12e>
> 286a: R_X86_64_PC32 debug_lockdep_rcu_enabled-0x4
> 286e: 85 c0 test %eax,%eax
> 2870: 0f 85 3c ff ff ff jne 27b2 <syscall_trace_leave+0x72>
> 2876: e9 68 ff ff ff jmpq 27e3 <syscall_trace_leave+0xa3>
> 287b: e8 00 00 00 00 callq 2880 <syscall_trace_leave+0x140>
> 287c: R_X86_64_PC32 ___preempt_schedule_context-0x4
> 2880: eb 96 jmp 2818 <syscall_trace_leave+0xd8>
> 2882: 66 0f 1f 44 00 00 nopw 0x0(%rax,%rax,1)
> 2888: 65 48 8b 04 25 00 00 mov %gs:0x0,%rax
> 288f: 00 00
> 288d: R_X86_64_32S kernel_stack
> 2891: 48 8b 80 38 e0 ff ff mov -0x1fc8(%rax),%rax
> 2898: 31 f6 xor %esi,%esi
> 289a: a8 01 test $0x1,%al
> 289c: 75 a2 jne 2840 <syscall_trace_leave+0x100>
> 289e: eb a8 jmp 2848 <syscall_trace_leave+0x108>
> 28a0: e8 00 00 00 00 callq 28a5 <syscall_trace_leave+0x165>
> 28a1: R_X86_64_PC32 context_tracking_user_enter-0x4
> 28a5: 48 8b 5d e8 mov -0x18(%rbp),%rbx
> 28a9: 4c 8b 65 f0 mov -0x10(%rbp),%r12
> 28ad: 4c 8b 6d f8 mov -0x8(%rbp),%r13
> 28b1: c9 leaveq
> 28b2: c3 retq
>
>
> Thanks,
> Sasha
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: ptrace: gpf in syscall_trace_enter
2014-05-07 16:06 ` Steven Rostedt
@ 2014-05-07 19:51 ` Andy Lutomirski
2014-05-07 22:55 ` Mathieu Desnoyers
1 sibling, 0 replies; 12+ messages in thread
From: Andy Lutomirski @ 2014-05-07 19:51 UTC (permalink / raw)
To: Steven Rostedt, Sasha Levin
Cc: Oleg Nesterov, roland, LKML, Dave Jones, Mathieu Desnoyers
On 05/07/2014 09:06 AM, Steven Rostedt wrote:
> [ adding Mathieu as well, as this is tracepoint code ]
>
> On Wed, 07 May 2014 11:23:36 -0400
> Sasha Levin <sasha.levin@oracle.com> wrote:
>
>> On 05/07/2014 10:31 AM, Steven Rostedt wrote:
>>> On Wed, 7 May 2014 16:04:22 +0200
>>> Oleg Nesterov <oleg@redhat.com> wrote:
>>>
>>>> On 05/06, Sasha Levin wrote:
>>>>>
>>>>> On 05/06/2014 08:36 PM, Sasha Levin wrote:
>>>>>> Hi all,
>>>>>>
>>>>>> While fuzzing with trinity inside a KVM tools guest running the latest -next
>>>>>> kernel I've stumbled on the following spew:
>>>>>
>>>>> And another similar trace:
>>>>
>>>> Again, this looks like __DO_TRACE() trying to call it_func_ptr->func().
>>>
>>> Really? Can I see an objdump of the location of the crash. Preferably
>>> the entire function.
>>
>> 0000000000002740 <syscall_trace_leave>:
>> 2740: e8 00 00 00 00 callq 2745 <syscall_trace_leave+0x5>
>> 2741: R_X86_64_PC32 __fentry__-0x4
>> 2745: 55 push %rbp
>> 2746: 48 89 e5 mov %rsp,%rbp
>> 2749: 48 83 ec 20 sub $0x20,%rsp
>> 274d: 48 89 5d e8 mov %rbx,-0x18(%rbp)
>> 2751: 48 89 fb mov %rdi,%rbx
>> 2754: 4c 89 65 f0 mov %r12,-0x10(%rbp)
>> 2758: 4c 89 6d f8 mov %r13,-0x8(%rbp)
>> 275c: 0f 1f 44 00 00 nopl 0x0(%rax,%rax,1)
>> 2761: 65 48 8b 04 25 00 00 mov %gs:0x0,%rax
>> 2768: 00 00
>> 2766: R_X86_64_32S current_task
>> 276a: 48 83 b8 b8 0b 00 00 cmpq $0x0,0xbb8(%rax)
>> 2771: 00
>> 2772: 74 1c je 2790 <syscall_trace_leave+0x50>
>> 2774: 48 8b 73 50 mov 0x50(%rbx),%rsi
>> 2778: 31 ff xor %edi,%edi
>> 277a: 48 81 fe 00 f0 ff ff cmp $0xfffffffffffff000,%rsi
>> 2781: 40 0f 96 c7 setbe %dil
>> 2785: e8 00 00 00 00 callq 278a <syscall_trace_leave+0x4a>
>> 2786: R_X86_64_PC32 __audit_syscall_exit-0x4
>> 278a: 66 0f 1f 44 00 00 nopw 0x0(%rax,%rax,1)
>> 2790: 65 48 8b 04 25 00 00 mov %gs:0x0,%rax
>> 2797: 00 00
>> 2795: R_X86_64_32S kernel_stack
>> 2799: 48 8b 80 38 e0 ff ff mov -0x1fc8(%rax),%rax
>> 27a0: a9 00 00 00 10 test $0x10000000,%eax
>> 27a5: 74 71 je 2818 <syscall_trace_leave+0xd8>
>> 27a7: 4c 8b 6b 50 mov 0x50(%rbx),%r13
>> 27ab: 0f 1f 44 00 00 nopl 0x0(%rax,%rax,1)
>
> Here's the static_key branch
>
>> 27b0: eb 62 jmp 2814 <syscall_trace_leave+0xd4>
>> 27b2: 80 3d 00 00 00 00 00 cmpb $0x0,0x0(%rip) # 27b9 <syscall_trace_leave+0x79>
>> 27b4: R_X86_64_PC32 .data.unlikely-0x4
>> 27b9: 75 28 jne 27e3 <syscall_trace_leave+0xa3>
>> 27bb: e8 00 00 00 00 callq 27c0 <syscall_trace_leave+0x80>
>> 27bc: R_X86_64_PC32 .text.unlikely-0x4
>
> Interesting that we have a "callq" to the next instruction.
I think this is just unrelocated output, presumably from objdump -dr
something.o. objdump -d vmlinux will give better output.
--Andy, who got confused by exactly the same thing while debugging the vdso
^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: ptrace: gpf in syscall_trace_enter
2014-05-07 16:06 ` Steven Rostedt
2014-05-07 19:51 ` Andy Lutomirski
@ 2014-05-07 22:55 ` Mathieu Desnoyers
1 sibling, 0 replies; 12+ messages in thread
From: Mathieu Desnoyers @ 2014-05-07 22:55 UTC (permalink / raw)
To: Steven Rostedt, Sasha Levin; +Cc: Oleg Nesterov, roland, LKML, Dave Jones
[-- Attachment #1: Type: text/plain, Size: 8696 bytes --]
----- Original Message -----
> From: "Steven Rostedt" <rostedt@goodmis.org>
> To: "Sasha Levin" <sasha.levin@oracle.com>
> Cc: "Oleg Nesterov" <oleg@redhat.com>, roland@redhat.com, "LKML" <linux-kernel@vger.kernel.org>, "Dave Jones"
> <davej@redhat.com>, "Mathieu Desnoyers" <mathieu.desnoyers@efficios.com>
> Sent: Wednesday, May 7, 2014 12:06:27 PM
> Subject: Re: ptrace: gpf in syscall_trace_enter
>
> [ adding Mathieu as well, as this is tracepoint code ]
>
> On Wed, 07 May 2014 11:23:36 -0400
> Sasha Levin <sasha.levin@oracle.com> wrote:
>
> > On 05/07/2014 10:31 AM, Steven Rostedt wrote:
> > > On Wed, 7 May 2014 16:04:22 +0200
> > > Oleg Nesterov <oleg@redhat.com> wrote:
> > >
> > >> On 05/06, Sasha Levin wrote:
> > >>>
> > >>> On 05/06/2014 08:36 PM, Sasha Levin wrote:
> > >>>> Hi all,
> > >>>>
> > >>>> While fuzzing with trinity inside a KVM tools guest running the latest
> > >>>> -next
> > >>>> kernel I've stumbled on the following spew:
> > >>>
> > >>> And another similar trace:
> > >>
> > >> Again, this looks like __DO_TRACE() trying to call it_func_ptr->func().
> > >
> > > Really? Can I see an objdump of the location of the crash. Preferably
> > > the entire function.
> >
> > 0000000000002740 <syscall_trace_leave>:
> > 2740: e8 00 00 00 00 callq 2745 <syscall_trace_leave+0x5>
> > 2741: R_X86_64_PC32 __fentry__-0x4
> > 2745: 55 push %rbp
> > 2746: 48 89 e5 mov %rsp,%rbp
> > 2749: 48 83 ec 20 sub $0x20,%rsp
> > 274d: 48 89 5d e8 mov %rbx,-0x18(%rbp)
> > 2751: 48 89 fb mov %rdi,%rbx
> > 2754: 4c 89 65 f0 mov %r12,-0x10(%rbp)
> > 2758: 4c 89 6d f8 mov %r13,-0x8(%rbp)
> > 275c: 0f 1f 44 00 00 nopl 0x0(%rax,%rax,1)
> > 2761: 65 48 8b 04 25 00 00 mov %gs:0x0,%rax
> > 2768: 00 00
> > 2766: R_X86_64_32S current_task
> > 276a: 48 83 b8 b8 0b 00 00 cmpq $0x0,0xbb8(%rax)
> > 2771: 00
> > 2772: 74 1c je 2790 <syscall_trace_leave+0x50>
> > 2774: 48 8b 73 50 mov 0x50(%rbx),%rsi
> > 2778: 31 ff xor %edi,%edi
> > 277a: 48 81 fe 00 f0 ff ff cmp $0xfffffffffffff000,%rsi
> > 2781: 40 0f 96 c7 setbe %dil
> > 2785: e8 00 00 00 00 callq 278a <syscall_trace_leave+0x4a>
> > 2786: R_X86_64_PC32 __audit_syscall_exit-0x4
> > 278a: 66 0f 1f 44 00 00 nopw 0x0(%rax,%rax,1)
> > 2790: 65 48 8b 04 25 00 00 mov %gs:0x0,%rax
> > 2797: 00 00
> > 2795: R_X86_64_32S kernel_stack
> > 2799: 48 8b 80 38 e0 ff ff mov -0x1fc8(%rax),%rax
> > 27a0: a9 00 00 00 10 test $0x10000000,%eax
> > 27a5: 74 71 je 2818 <syscall_trace_leave+0xd8>
> > 27a7: 4c 8b 6b 50 mov 0x50(%rbx),%r13
> > 27ab: 0f 1f 44 00 00 nopl 0x0(%rax,%rax,1)
>
> Here's the static_key branch
>
> > 27b0: eb 62 jmp 2814 <syscall_trace_leave+0xd4>
> > 27b2: 80 3d 00 00 00 00 00 cmpb $0x0,0x0(%rip) # 27b9
> > <syscall_trace_leave+0x79>
> > 27b4: R_X86_64_PC32 .data.unlikely-0x4
> > 27b9: 75 28 jne 27e3 <syscall_trace_leave+0xa3>
> > 27bb: e8 00 00 00 00 callq 27c0 <syscall_trace_leave+0x80>
> > 27bc: R_X86_64_PC32 .text.unlikely-0x4
>
> Interesting that we have a "callq" to the next instruction.
>
> > 27c0: 85 c0 test %eax,%eax
> > 27c2: 75 1f jne 27e3 <syscall_trace_leave+0xa3>
> > 27c4: 48 c7 c2 00 00 00 00 mov $0x0,%rdx
> > 27c7: R_X86_64_32S .rodata.str1.8+0x60
> > 27cb: be 3e 00 00 00 mov $0x3e,%esi
> > 27d0: 48 c7 c7 00 00 00 00 mov $0x0,%rdi
> > 27d3: R_X86_64_32S .rodata.str1.8+0x90
> > 27d7: c6 05 00 00 00 00 01 movb $0x1,0x0(%rip) # 27de
> > <syscall_trace_leave+0x9e>
> > 27d9: R_X86_64_PC32 .data.unlikely-0x4
> > 27de: e8 00 00 00 00 callq 27e3 <syscall_trace_leave+0xa3>
> > 27df: R_X86_64_PC32 lockdep_rcu_suspicious-0x4
>
> OK, rcu debugging is on. Not really a factor, just making notes.
>
>
> > 27e3: 4d 85 e4 test %r12,%r12
>
> %r12 is the it_func_ptr
>
> > 27e6: 75 10 jne 27f8 <syscall_trace_leave+0xb8>
> > 27e8: 65 ff 0c 25 00 00 00 decl %gs:0x0
> > 27ef: 00
> > 27ec: R_X86_64_32S __preempt_count
> > 27f0: 0f 84 85 00 00 00 je 287b <syscall_trace_leave+0x13b>
> > 27f6: eb 1c jmp 2814 <syscall_trace_leave+0xd4>
> > 27f8: 49 8b 7c 24 08 mov 0x8(%r12),%rdi
> > 27fd: 4c 89 ea mov %r13,%rdx
> > 2800: 48 89 de mov %rbx,%rsi
> > 2803: 41 ff 14 24 callq *(%r12)
>
> As I stated, I didn't need the offset that I asked for, but the
> machine code had the information I needed:
>
> 24 08 4c 89 ea 48 89 de <41> ff 14 24 49 83 c4 10 49
>
> Which matches 2803.
>
> From your dump:
>
> R10: 0000000000000000 R11: 0000000000000000 R12: 000000000000000c
>
> Yeah, that's a bad pointer.
>
> OK, for some reason, funcs got 0xc?
Oh crap, I think I made a stupid mistake there. Calling call_rcu to free
the old func before rcu_assign_pointer publishes the new func. Can you try
the attached patch ? (sorry for no inlining, using a dumb mail client here)
Thanks,
Mathieu
>
> -- Steve
>
>
> > 2807: 49 83 c4 10 add $0x10,%r12
> > 280b: 49 83 3c 24 00 cmpq $0x0,(%r12)
> > 2810: 75 e6 jne 27f8 <syscall_trace_leave+0xb8>
> > 2812: eb d4 jmp 27e8 <syscall_trace_leave+0xa8>
> > 2814: 0f 1f 40 00 nopl 0x0(%rax)
> > 2818: 65 48 8b 04 25 00 00 mov %gs:0x0,%rax
> > 281f: 00 00
> > 281d: R_X86_64_32S kernel_stack
> > 2821: 48 8b 90 38 e0 ff ff mov -0x1fc8(%rax),%rdx
> > 2828: 83 e2 10 and $0x10,%edx
> > 282b: 74 5b je 2888 <syscall_trace_leave+0x148>
> > 282d: 48 8b 80 38 e0 ff ff mov -0x1fc8(%rax),%rax
> > 2834: a8 40 test $0x40,%al
> > 2836: 75 50 jne 2888 <syscall_trace_leave+0x148>
> > 2838: be 01 00 00 00 mov $0x1,%esi
> > 283d: 0f 1f 00 nopl (%rax)
> > 2840: 48 89 df mov %rbx,%rdi
> > 2843: e8 f8 fa ff ff callq 2340 <tracehook_report_syscall_exit>
> > 2848: 0f 1f 44 00 00 nopl 0x0(%rax,%rax,1)
> > 284d: eb 56 jmp 28a5 <syscall_trace_leave+0x165>
> > 284f: 90 nop
> > 2850: e8 00 00 00 00 callq 2855 <syscall_trace_leave+0x115>
> > 2851: R_X86_64_PC32 context_tracking_user_exit-0x4
> > 2855: e9 07 ff ff ff jmpq 2761 <syscall_trace_leave+0x21>
> > 285a: 65 ff 04 25 00 00 00 incl %gs:0x0
> > 2861: 00
> > 285e: R_X86_64_32S __preempt_count
> > 2862: 4c 8b 25 00 00 00 00 mov 0x0(%rip),%r12 # 2869
> > <syscall_trace_leave+0x129>
> > 2865: R_X86_64_PC32 __tracepoint_sys_exit+0x2c
> > 2869: e8 00 00 00 00 callq 286e <syscall_trace_leave+0x12e>
> > 286a: R_X86_64_PC32 debug_lockdep_rcu_enabled-0x4
> > 286e: 85 c0 test %eax,%eax
> > 2870: 0f 85 3c ff ff ff jne 27b2 <syscall_trace_leave+0x72>
> > 2876: e9 68 ff ff ff jmpq 27e3 <syscall_trace_leave+0xa3>
> > 287b: e8 00 00 00 00 callq 2880 <syscall_trace_leave+0x140>
> > 287c: R_X86_64_PC32 ___preempt_schedule_context-0x4
> > 2880: eb 96 jmp 2818 <syscall_trace_leave+0xd8>
> > 2882: 66 0f 1f 44 00 00 nopw 0x0(%rax,%rax,1)
> > 2888: 65 48 8b 04 25 00 00 mov %gs:0x0,%rax
> > 288f: 00 00
> > 288d: R_X86_64_32S kernel_stack
> > 2891: 48 8b 80 38 e0 ff ff mov -0x1fc8(%rax),%rax
> > 2898: 31 f6 xor %esi,%esi
> > 289a: a8 01 test $0x1,%al
> > 289c: 75 a2 jne 2840 <syscall_trace_leave+0x100>
> > 289e: eb a8 jmp 2848 <syscall_trace_leave+0x108>
> > 28a0: e8 00 00 00 00 callq 28a5 <syscall_trace_leave+0x165>
> > 28a1: R_X86_64_PC32 context_tracking_user_enter-0x4
> > 28a5: 48 8b 5d e8 mov -0x18(%rbp),%rbx
> > 28a9: 4c 8b 65 f0 mov -0x10(%rbp),%r12
> > 28ad: 4c 8b 6d f8 mov -0x8(%rbp),%r13
> > 28b1: c9 leaveq
> > 28b2: c3 retq
> >
> >
> > Thanks,
> > Sasha
>
>
--
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com
[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #2: fix-tp-release-probe.patch --]
[-- Type: text/x-patch; name=fix-tp-release-probe.patch, Size: 1272 bytes --]
commit 13c8bda5154665f4499b31030d74665207025d24
Author: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Date: Wed May 7 18:48:53 2014 -0400
Fix: tracepoint: release old probe after rcu assign pointer
Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
diff --git a/kernel/tracepoint.c b/kernel/tracepoint.c
index ac5b23c..6620e58 100644
--- a/kernel/tracepoint.c
+++ b/kernel/tracepoint.c
@@ -188,7 +188,6 @@ static int tracepoint_add_func(struct tracepoint *tp,
WARN_ON_ONCE(1);
return PTR_ERR(old);
}
- release_probes(old);
/*
* rcu_assign_pointer has a smp_wmb() which makes sure that the new
@@ -200,6 +199,7 @@ static int tracepoint_add_func(struct tracepoint *tp,
rcu_assign_pointer(tp->funcs, tp_funcs);
if (!static_key_enabled(&tp->key))
static_key_slow_inc(&tp->key);
+ release_probes(old);
return 0;
}
@@ -221,7 +221,6 @@ static int tracepoint_remove_func(struct tracepoint *tp,
WARN_ON_ONCE(1);
return PTR_ERR(old);
}
- release_probes(old);
if (!tp_funcs) {
/* Removed last function */
@@ -232,6 +231,7 @@ static int tracepoint_remove_func(struct tracepoint *tp,
static_key_slow_dec(&tp->key);
}
rcu_assign_pointer(tp->funcs, tp_funcs);
+ release_probes(old);
return 0;
}
^ permalink raw reply related [flat|nested] 12+ messages in thread
end of thread, other threads:[~2014-05-07 22:55 UTC | newest]
Thread overview: 12+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2014-05-07 0:36 ptrace: gpf in syscall_trace_enter Sasha Levin
2014-05-07 2:50 ` Sasha Levin
2014-05-07 14:04 ` Oleg Nesterov
2014-05-07 14:31 ` Steven Rostedt
2014-05-07 15:23 ` Sasha Levin
2014-05-07 16:06 ` Steven Rostedt
2014-05-07 19:51 ` Andy Lutomirski
2014-05-07 22:55 ` Mathieu Desnoyers
2014-05-07 15:49 ` Steven Rostedt
2014-05-07 15:52 ` Sasha Levin
2014-05-07 16:00 ` Steven Rostedt
2014-05-07 14:00 ` Oleg Nesterov
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).