Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]
Groups > linux.kernel > #1457455 > unrolled thread
| Started by | Josh Poimboeuf <jpoimboe@redhat.com> |
|---|---|
| First post | 2016-08-07 15:50 +0200 |
| Last post | 2016-08-08 17:00 +0200 |
| Articles | 4 — 3 participants |
Back to article view | Back to linux.kernel
This discussion starts older than the indexed window; earlier articles aren't shown. The article labeled Started by
below is the oldest one visible, not the original post.
Re: [lkp] [x86/mm/64] 4bc0303aff: BUG: stack guard page was hit at ffffc900001bbff8 Josh Poimboeuf <jpoimboe@redhat.com> - 2016-08-07 15:50 +0200
Re: [lkp] [x86/mm/64] 4bc0303aff: BUG: stack guard page was hit at ffffc900001bbff8 Steven Rostedt <rostedt@goodmis.org> - 2016-08-08 17:00 +0200
Re: [lkp] [x86/mm/64] 4bc0303aff: BUG: stack guard page was hit at ffffc900001bbff8 Andy Lutomirski <luto@amacapital.net> - 2016-08-10 21:00 +0200
Re: [lkp] [x86/mm/64] 4bc0303aff: BUG: stack guard page was hit at ffffc900001bbff8 Steven Rostedt <rostedt@goodmis.org> - 2016-08-08 17:00 +0200
| From | Josh Poimboeuf <jpoimboe@redhat.com> |
|---|---|
| Date | 2016-08-07 15:50 +0200 |
| Subject | Re: [lkp] [x86/mm/64] 4bc0303aff: BUG: stack guard page was hit at ffffc900001bbff8 |
| Message-ID | <s3wCK-4si-33@gated-at.bofh.it> |
On Sun, Aug 07, 2016 at 01:58:16AM -0700, Andy Lutomirski wrote:
> Hi Steven and Josh-
>
> This test recursively faulted in is_ftrace_trampoline. It's not
> immediately obvious to me what went wrong -- is_ftrace_trampoline
> doesn't seem to be dereferencing the provided address.
It seems to be faulting because one of the entries in the
ftrace_ops_list is corrupt.
00000000000013cc <is_ftrace_trampoline>:
13cc: 55 push %rbp
13cd: 65 ff 05 00 00 00 00 incl %gs:0x0(%rip) # 13d4 <is_ftrace_trampoline+0x8>
13d0: R_X86_64_PC32 __preempt_count-0x4
13d4: 48 89 e5 mov %rsp,%rbp
13d7: 41 54 push %r12
13d9: 49 89 fc mov %rdi,%r12
13dc: 53 push %rbx
13dd: 48 8b 1d 00 00 00 00 mov 0x0(%rip),%rbx # 13e4 <is_ftrace_trampoline+0x18>
13e0: R_X86_64_PC32 .data..read_mostly+0x7c4
13e4: e8 00 00 00 00 callq 13e9 <is_ftrace_trampoline+0x1d>
13e5: R_X86_64_PC32 debug_lockdep_rcu_enabled-0x4
13e9: 48 8b 83 98 01 00 00 mov 0x198(%rbx),%rax
^^^^ faults here because rbx (ops) is a bad pointer (RBX: 6b6b6b6b6b6b6b6b)
13f0: 48 85 c0 test %rax,%rax
13f3: 74 19 je 140e <is_ftrace_trampoline+0x42>
13f5: 4c 39 e0 cmp %r12,%rax
13f8: 48 8b 93 a0 01 00 00 mov 0x1a0(%rbx),%rdx
13ff: 77 0d ja 140e <is_ftrace_trampoline+0x42>
1401: 48 85 d2 test %rdx,%rdx
1404: 74 08 je 140e <is_ftrace_trampoline+0x42>
1406: 48 01 d0 add %rdx,%rax
1409: 49 39 c4 cmp %rax,%r12
140c: 72 21 jb 142f <is_ftrace_trampoline+0x63>
140e: 48 8b 5b 08 mov 0x8(%rbx),%rbx
1412: e8 00 00 00 00 callq 1417 <is_ftrace_trampoline+0x4b>
1413: R_X86_64_PC32 debug_lockdep_rcu_enabled-0x4
1417: 48 81 fb 00 00 00 00 cmp $0x0,%rbx
141a: R_X86_64_32S .data..read_mostly+0x800
141e: 0f 95 c2 setne %dl
1421: 48 85 db test %rbx,%rbx
1424: 0f 95 c0 setne %al
1427: 84 c2 test %al,%dl
1429: 75 be jne 13e9 <is_ftrace_trampoline+0x1d>
Note that shortly before the recursive fault started, another ftrace
error occurred:
[ 59.235185] ftrace: Failed on adding breakpoints (124910):
[ 59.848448] ------------[ cut here ]------------
[ 59.853011] WARNING: CPU: 0 PID: 1625 at kernel/trace/ftrace.c:2006 ftrace_bug+0x102/0x24a
[ 59.898634] Modules linked in:
[ 59.902617] CPU: 0 PID: 1625 Comm: trinity-main Not tainted 4.7.0-06443-g4bc0303 #82
[ 59.909984] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 59.926316] 0000000000000000 ffffc90004f9fbe0 ffffffff81780126 0000000000000000
[ 59.946998] 0000000000000000 ffffc90004f9fc20 ffffffff810e4fd9 000007d600000000
[ 59.955226] ffff880031ebfee0 ffffffff8324c9a0 ffffffff85652b30 0000000000000001
[ 59.976130] Call Trace:
[ 59.979819] [<ffffffff81780126>] dump_stack+0x82/0xb8
[ 59.997638] [<ffffffff810e4fd9>] __warn+0xc2/0xdd
[ 60.001832] [<ffffffff810e50b0>] warn_slowpath_null+0x1d/0x1f
[ 60.006141] [<ffffffff81187920>] ftrace_bug+0x102/0x24a
[ 60.023201] [<ffffffff810979c6>] ftrace_replace_code+0x227/0x350
[ 60.027709] [<ffffffff81188065>] ftrace_modify_all_code+0x41/0xc9
[ 60.032357] [<ffffffff81097aff>] arch_ftrace_update_code+0x10/0x19
[ 60.049494] [<ffffffff81186b6a>] ftrace_run_update_code+0x1e/0x3f
[ 60.054082] [<ffffffff81186bbd>] ftrace_startup_enable+0x32/0x34
[ 60.070761] [<ffffffff81186d54>] ftrace_startup+0x195/0x1a7
[ 60.075193] [<ffffffff81186d8c>] register_ftrace_function+0x26/0x3c
[ 60.079704] [<ffffffff811a1163>] perf_ftrace_event_register+0x42/0xe7
[ 60.114514] [<ffffffff811a0fd6>] perf_trace_init+0x29d/0x2dc
[ 60.119309] [<ffffffff811ad345>] perf_tp_event_init+0x29/0x3b
[ 60.124026] [<ffffffff811ade86>] perf_try_init_event+0x46/0x76
[ 60.147114] [<ffffffff811b0034>] perf_event_alloc+0x3c4/0x6ad
[ 60.169443] [<ffffffff811b2e47>] SYSC_perf_event_open+0x490/0xb2c
[ 60.174482] [<ffffffff811b6b7b>] SyS_perf_event_open+0x9/0xb
[ 60.197378] [<ffffffff81003c42>] do_int80_syscall_32+0x65/0x74
[ 60.202211] [<ffffffff82ee2598>] entry_INT80_compat+0x38/0x50
[ 60.221358] ---[ end trace e31eb279467a53f4 ]---
[ 60.604454] ftrace faulted on writing [<ffffffff8324c9a0>] lkdtm_rodata_do_nothing+0x0/0x10
[ 60.612963] Setting ftrace call site to call ftrace function
[ 60.653362] ftrace record flags: 10000001
[ 60.658136] (1)
expected tramp: ffffffff82ee25d0
This seems to be an expected error caused by the test case (tracing an
rodata function). But maybe there's something in the ftrace error path
which corrupts ftrace_ops_list somehow? Or triggers a use-after-free?
>
> On Fri, Aug 5, 2016 at 7:07 AM, kernel test robot <xiaolong.ye@intel.com> wrote:
> >
> > FYI, we noticed the following commit:
> >
> > https://git.kernel.org/pub/scm/linux/kernel/git/luto/linux.git x86/vmap_stack
> > commit 4bc0303affaa75add8c5c2fbfd6d27d9b644fa0d ("x86/mm/64: Enable vmapped stacks")
> >
> > in testcase: boot
> >
> > on test machine: 1 threads qemu-system-x86_64 -enable-kvm -cpu Westmere with 512M memory
> >
> > caused below changes:
> >
> >
> > +-------------------------------------------------------+------------+------------+
> > | | ee12d3b8b1 | 4bc0303aff |
> > +-------------------------------------------------------+------------+------------+
> > | boot_successes | 388 | 398 |
> > | boot_failures | 32 | 39 |
> > | WARNING:at_kernel/trace/ftrace.c:#ftrace_bug | 32 | 39 |
> > | general_protection_fault:#[##]SMP | 32 | 37 |
> > | RIP:is_ftrace_trampoline | 32 | 37 |
> > | Kernel_panic-not_syncing:Fatal_exception_in_interrupt | 18 | 8 |
> > | backtrace:perf_ftrace_event_register | 32 | 39 |
> > | backtrace:perf_trace_init | 32 | 39 |
> > | backtrace:perf_tp_event_init | 32 | 39 |
> > | backtrace:perf_try_init_event | 32 | 39 |
> > | backtrace:SYSC_perf_event_open | 31 | 38 |
> > | backtrace:SyS_perf_event_open | 32 | 39 |
> > | Kernel_panic-not_syncing:Fatal_exception | 12 | 13 |
> > | WARNING:at_include/linux/uaccess.h:#pagefault_enable | 4 | |
> > | RIP:#d:[<#>][<#>]is_ftrace_trampoline | 1 | |
> > | BUG:kernel_test_hang | 1 | 16 |
> > | BUG:unable_to_handle_kernel | 1 | |
> > | Oops | 1 | |
> > | RIP:task_curr | 1 | |
> > | BUG:stack_guard_page_was_hit_at#(stack_is#..#) | 0 | 17 |
> > | RIP:fb_get_color_depth | 0 | 3 |
> > | RIP:cfb_imageblit | 0 | 8 |
> > | RIP:fb_get_buffer_offset | 0 | 4 |
> > | RIP:get_attribute | 0 | 1 |
> > | RIP:number | 0 | 1 |
> > +-------------------------------------------------------+------------+------------+
> >
> > [ 68.243445] Call Trace:
> > [ 68.244310] general protection fault: 0000 [#18] SMP
> > [ 68.249171] BUG: stack guard page was hit at ffffc900001bbff8 (stack is ffffc900001bc000..ffffc900001bffff)
> > [ 68.249174] kernel stack overflow (double-fault): 0000 [#19] SMP
> > [ 68.249175] Modules linked in:
> > [ 68.249178] CPU: 0 PID: 6 Comm: kworker/u2:0 Tainted: G W 4.7.0-06443-g4bc0303 #82
> > [ 68.249179] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
> > [ 68.249185] Workqueue: netns cleanup_net
> > [ 68.249187] task: ffff8800314ec180 task.stack: ffffc900001bc000
> > [ 68.249192] RIP: 0010:[<ffffffff817f31f0>] [<ffffffff817f31f0>] fb_get_buffer_offset+0x18/0x8c
> > [ 68.249193] RSP: 0000:ffffc900001bc000 EFLAGS: 00010002
> > [ 68.249194] RAX: 0000000000000001 RBX: ffff88002deab000 RCX: 0000000000000001
> > [ 68.249195] RDX: 0000000000000001 RSI: ffff88002deab320 RDI: ffff88002deab000
> > [ 68.249197] RBP: ffffc900001bc018 R08: 0000000000000000 R09: 0000000000000048
> > [ 68.249198] R10: 0000000000000000 R11: ffffffff83174d50 R12: ffff88002cb68000
> > [ 68.249199] R13: 00000000ffffffff R14: 0000000000000010 R15: ffff880031c0d800
> > [ 68.249202] FS: 0000000000000000(0000) GS:ffff880033200000(0000) knlGS:0000000000000000
> > [ 68.249203] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> > [ 68.249204] CR2: ffffc900001bbff8 CR3: 0000000004021000 CR4: 00000000000006f0
> > [ 68.249208] DR0: 0000000008c45968 DR1: 0000000000000000 DR2: 0000000000000000
> > [ 68.249210] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000600
> > [ 68.249210] Stack:
> > [ 68.249211]
> >
> >
> > FYI, raw QEMU command line is:
> >
> > qemu-system-x86_64 -enable-kvm -cpu Westmere -kernel /pkg/linux/x86_64-allyesdebian/gcc-6/4bc0303affaa75add8c5c2fbfd6d27d9b644fa0d/vmlinuz-4.7.0-06443-g4bc0303 -append 'ip=::::vm-kbuild-yocto-ia32-29::dhcp root=/dev/ram0 user=lkp job=/lkp/scheduled/vm-kbuild-yocto-ia32-29/boot-1-yocto-minimal-i386.cgz-4bc0303affaa75add8c5c2fbfd6d27d9b644fa0d-20160801-54711-lk1j2k-228.yaml ARCH=x86_64 kconfig=x86_64-allyesdebian branch=linux-devel/devel-catchup-201607300515 commit=4bc0303affaa75add8c5c2fbfd6d27d9b644fa0d BOOT_IMAGE=/pkg/linux/x86_64-allyesdebian/gcc-6/4bc0303affaa75add8c5c2fbfd6d27d9b644fa0d/vmlinuz-4.7.0-06443-g4bc0303 max_uptime=600 RESULT_ROOT=/result/boot/1/vm-kbuild-yocto-ia32/yocto-minimal-i386.cgz/x86_64-allyesdebian/gcc-6/4bc0303affaa75add8c5c2fbfd6d27d9b644fa0d/227 LKP_SERVER=inn debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 systemd.log_level=err ignore_loglevel earlyprintk=ttyS0,115200 console=ttyS0,115200 console=tty0 vga=normal rw drbd.minor_count=8' -initrd /fs/sdh1/initrd-vm-kbuild-yocto-ia32-29 -m 832 -smp 1 -device e1000,netdev=net0 -netdev user,id=net0 -boot order=nc -no-reboot -watchdog i6300esb -watchdog-action debug -rtc base=localtime -drive file=/fs/sdh1/disk0-vm-kbuild-yocto-ia32-29,media=disk,if=virtio -pidfile /dev/shm/kboot/pid-vm-kbuild-yocto-ia32-29 -serial file:/dev/shm/kboot/serial-vm-kbuild-yocto-ia32-29 -daemonize -display none -monitor null
> >
> >
> >
> >
> >
> > Thanks,
> > Xiaolong
>
>
>
> --
> Andy Lutomirski
> AMA Capital Management, LLC
--
Josh
[toc] | [next] | [standalone]
| From | Steven Rostedt <rostedt@goodmis.org> |
|---|---|
| Date | 2016-08-08 17:00 +0200 |
| Message-ID | <s3Uc1-2G2-17@gated-at.bofh.it> |
| In reply to | #1457455 |
On Mon, 8 Aug 2016 10:56:49 -0400
Steven Rostedt <rostedt@goodmis.org> wrote:
> Yeah, looking at the error path, if registering an ops cause a
> ftrace_bug, then ftrace is completely (well, mostly) which means that
^
I left out the word... disabled
> if the user unregistered the ops, nothing would happen. It which case,
"In which case"
> if it freed the ops after it failed, then we can have this case.
>
Not enough coffee on this Monday morning.
-- Steve
[toc] | [prev] | [next] | [standalone]
| From | Andy Lutomirski <luto@amacapital.net> |
|---|---|
| Date | 2016-08-10 21:00 +0200 |
| Subject | Re: [lkp] [x86/mm/64] 4bc0303aff: BUG: stack guard page was hit at ffffc900001bbff8 |
| Message-ID | <s4GTp-n4-71@gated-at.bofh.it> |
| In reply to | #1457853 |
On Mon, Aug 8, 2016 at 7:58 AM, Steven Rostedt <rostedt@goodmis.org> wrote: > On Mon, 8 Aug 2016 10:56:49 -0400 > Steven Rostedt <rostedt@goodmis.org> wrote: > >> Yeah, looking at the error path, if registering an ops cause a >> ftrace_bug, then ftrace is completely (well, mostly) which means that > ^ > I left out the word... disabled > >> if the user unregistered the ops, nothing would happen. It which case, > > "In which case" > >> if it freed the ops after it failed, then we can have this case. >> > > Not enough coffee on this Monday morning. > I suspect I can't usefully reproduce this bug without or without the patch -- it took 0day weeks to hit it. Want to just take it via your tree or send it to Ingo directly?
[toc] | [prev] | [next] | [standalone]
| From | Steven Rostedt <rostedt@goodmis.org> |
|---|---|
| Date | 2016-08-08 17:00 +0200 |
| Message-ID | <s3Uc1-2G2-19@gated-at.bofh.it> |
| In reply to | #1457455 |
On Sun, 7 Aug 2016 08:43:02 -0500
Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> Note that shortly before the recursive fault started, another ftrace
> error occurred:
>
> [ 59.235185] ftrace: Failed on adding breakpoints (124910):
> [ 59.848448] ------------[ cut here ]------------
> [ 59.853011] WARNING: CPU: 0 PID: 1625 at kernel/trace/ftrace.c:2006 ftrace_bug+0x102/0x24a
> [ 59.898634] Modules linked in:
> [ 59.902617] CPU: 0 PID: 1625 Comm: trinity-main Not tainted 4.7.0-06443-g4bc0303 #82
> [ 59.909984] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
> [ 59.926316] 0000000000000000 ffffc90004f9fbe0 ffffffff81780126 0000000000000000
> [ 59.946998] 0000000000000000 ffffc90004f9fc20 ffffffff810e4fd9 000007d600000000
> [ 59.955226] ffff880031ebfee0 ffffffff8324c9a0 ffffffff85652b30 0000000000000001
> [ 59.976130] Call Trace:
> [ 59.979819] [<ffffffff81780126>] dump_stack+0x82/0xb8
> [ 59.997638] [<ffffffff810e4fd9>] __warn+0xc2/0xdd
> [ 60.001832] [<ffffffff810e50b0>] warn_slowpath_null+0x1d/0x1f
> [ 60.006141] [<ffffffff81187920>] ftrace_bug+0x102/0x24a
> [ 60.023201] [<ffffffff810979c6>] ftrace_replace_code+0x227/0x350
> [ 60.027709] [<ffffffff81188065>] ftrace_modify_all_code+0x41/0xc9
> [ 60.032357] [<ffffffff81097aff>] arch_ftrace_update_code+0x10/0x19
> [ 60.049494] [<ffffffff81186b6a>] ftrace_run_update_code+0x1e/0x3f
> [ 60.054082] [<ffffffff81186bbd>] ftrace_startup_enable+0x32/0x34
> [ 60.070761] [<ffffffff81186d54>] ftrace_startup+0x195/0x1a7
> [ 60.075193] [<ffffffff81186d8c>] register_ftrace_function+0x26/0x3c
> [ 60.079704] [<ffffffff811a1163>] perf_ftrace_event_register+0x42/0xe7
> [ 60.114514] [<ffffffff811a0fd6>] perf_trace_init+0x29d/0x2dc
> [ 60.119309] [<ffffffff811ad345>] perf_tp_event_init+0x29/0x3b
> [ 60.124026] [<ffffffff811ade86>] perf_try_init_event+0x46/0x76
> [ 60.147114] [<ffffffff811b0034>] perf_event_alloc+0x3c4/0x6ad
> [ 60.169443] [<ffffffff811b2e47>] SYSC_perf_event_open+0x490/0xb2c
> [ 60.174482] [<ffffffff811b6b7b>] SyS_perf_event_open+0x9/0xb
> [ 60.197378] [<ffffffff81003c42>] do_int80_syscall_32+0x65/0x74
> [ 60.202211] [<ffffffff82ee2598>] entry_INT80_compat+0x38/0x50
> [ 60.221358] ---[ end trace e31eb279467a53f4 ]---
> [ 60.604454] ftrace faulted on writing [<ffffffff8324c9a0>] lkdtm_rodata_do_nothing+0x0/0x10
> [ 60.612963] Setting ftrace call site to call ftrace function
> [ 60.653362] ftrace record flags: 10000001
> [ 60.658136] (1)
> expected tramp: ffffffff82ee25d0
>
> This seems to be an expected error caused by the test case (tracing an
> rodata function). But maybe there's something in the ftrace error path
> which corrupts ftrace_ops_list somehow? Or triggers a use-after-free?
>
Yeah, looking at the error path, if registering an ops cause a
ftrace_bug, then ftrace is completely (well, mostly) which means that
if the user unregistered the ops, nothing would happen. It which case,
if it freed the ops after it failed, then we can have this case.
Does the below patch fix things?
-- Steve
diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c
index 900dbb1efff2..cd194c1cf0fb 100644
--- a/kernel/trace/ftrace.c
+++ b/kernel/trace/ftrace.c
@@ -2685,6 +2685,12 @@ static int ftrace_startup(struct ftrace_ops *ops, int command)
ftrace_startup_enable(command);
+ /* If something went wrong, remove this ops */
+ if (unlikely(ftrace_disabled)) {
+ remove_ftrace_ops(&ftrace_ops_list, ops);
+ return -1;
+ }
+
ops->flags &= ~FTRACE_OPS_FL_ADDING;
return 0;
@@ -2694,8 +2700,11 @@ static int ftrace_shutdown(struct ftrace_ops *ops, int command)
{
int ret;
- if (unlikely(ftrace_disabled))
+ if (unlikely(ftrace_disabled)) {
+ /* Still try to remove the ops */
+ remove_ftrace_ops(&ftrace_ops_list, ops);
return -ENODEV;
+ }
ret = __unregister_ftrace_function(ops);
if (ret)
[toc] | [prev] | [standalone]
Back to top | Article view | linux.kernel
csiph-web