New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.

Issue 738553 link

Starred by 1 user

Issue metadata

Status: Verified
Owner:
Last visit > 30 days ago
Closed: Aug 2017
Cc:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 2
Type: Bug



Sign in to add a comment

clang: x86: stack guard page hit when generating backtrace (upstream kernel)

Project Member Reported by mka@chromium.org, Jun 30 2017

Issue description

A 4.12.0-rc6 kernel built with clang crashes on reboot:

[   19.715638] WARN_ON(pipe != PIPE_A && pipe != PIPE_B)
[   19.715681] ------------[ cut here ]------------
[   19.726670] WARNING: CPU: 0 PID: 1209 at /mnt/host/source/src/third_party/kernel/v4.4/drivers/gpu/drm/i915/intel_panel.c:771 vlv_disable_backlight+0x8e/0x92
[   19.742346] Modules linked in: uinput i2c_dev rtc_cmos bluetooth snd_hda_intel ecdh_generic snd_hda_codec snd_hwdep snd_hda_core snd_pcm snd_timer fuse cfg80211 nf_conntrack_ipv6 nf_defrag_ipv6 ip6table_filter ip6_tables r8152 mii
[   19.765255] CPU: 0 PID: 1209 Comm: DrmThread Not tainted 4.12.0-rc6-00021-g7ce09f1ed647 #77
[   19.774622] Hardware name: GOOGLE Squawks, BIOS Google_Squawks.5216.152.76 03/04/2016
[   19.783399] task: ffff880074d069c0 task.stack: ffffc9000057c000
[   19.790056] RIP: 0010:vlv_disable_backlight+0x8e/0x92
[   19.795710] RSP: 0018:ffffc9000057f7cd EFLAGS: 00010296
[   19.801574] RAX: 0000000000000029 RBX: 00000000ffffffff RCX: 0000000000000001
[   19.809560] RDX: 0000000000000000 RSI: 0000000000000086 RDI: ffffffff81c42150
[   19.817559] RBP: ffffc9000057f7e7 R08: 0000000000000029 R09: ffffffffffffffff
[   19.825567] R10: ffffffff819d2050 R11: 000000fd00000000 R12: ffff880077a88000
[   19.833574] R13: ffff880077ab9000 R14: ffff880077a88000 R15: ffff880077a85800
[   19.841559] FS:  00007f6abe5f0700(0000) GS:ffff88007ac00000(0000) knlGS:0000000000000000
[   19.850642] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   19.857071] CR2: 0000254947e20018 CR3: 0000000072640000 CR4: 00000000001006f0
[   19.865074] Call Trace:
[   19.867832] BUG: stack guard page was hit at ffffc90000580000 (stack is ffffc9000057c000..ffffc9000057ffff)
[   19.878725] kernel stack overflow (page fault): 0000 [#1] SMP
[   19.885146] Modules linked in: uinput i2c_dev rtc_cmos bluetooth snd_hda_intel ecdh_generic snd_hda_codec snd_hwdep snd_hda_core snd_pcm snd_timer fuse cfg80211 nf_conntrack_ipv6 nf_defrag_ipv6 ip6table_filter ip6_tables r8152 mii
[   19.908007] CPU: 0 PID: 1209 Comm: DrmThread Not tainted 4.12.0-rc6-00021-g7ce09f1ed647 #77
[   19.917340] Hardware name: GOOGLE Squawks, BIOS Google_Squawks.5216.152.76 03/04/2016
[   19.926091] task: ffff880074d069c0 task.stack: ffffc9000057c000
[   19.932709] RIP: 0010:show_trace_log_lvl+0x113/0x244
[   19.938254] RSP: 0018:ffffc9000057f430 EFLAGS: 00010283
[   19.944091] RAX: 0000000000000000 RBX: ffffc9000057fffd RCX: ffffffff81d7ce00
[   19.952056] RDX: ffffffff81cf0120 RSI: 0000000000000002 RDI: 000000002b00007f
[   19.960021] RBP: ffffc9000057f507 R08: 0000000200000000 R09: 00000000ffff0a30
[   19.967993] R10: 00000000ffff0a00 R11: 0000000000000000 R12: 000000002b00007f
[   19.975965] R13: 0000000000000000 R14: 0000000000000000 R15: ffff880074d069c0
[   19.983939] FS:  00007f6abe5f0700(0000) GS:ffff88007ac00000(0000) knlGS:0000000000000000
[   19.992981] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   19.999391] CR2: ffffc90000580000 CR3: 0000000072640000 CR4: 00000000001006f0
[   20.007363] Call Trace:
[   20.010097]  ? vlv_disable_backlight+0x8e/0x92
[   20.015060]  ? __warn+0xb5/0xf3
[   20.018567]  ? do_trap+0x12b/0x183
[   20.022363]  ? do_error_trap+0xb8/0xc7
[   20.026549]  ? vlv_disable_backlight+0x8e/0x92
[   20.031514]  ? invalid_op+0x18/0x20
[   20.035409]  ? vlv_disable_backlight+0x8e/0x92
[   20.040372]  ? intel_edp_backlight_off+0x42/0x45
[   20.045529]  ? intel_disable_dp+0x67/0x96
[   20.050007]  ? intel_encoders_disable+0x63/0x7c
[   20.055067]  ? i9xx_crtc_disable+0x56/0x338
[   20.059738]  ? intel_atomic_commit_tail+0x10a/0x111d
[   20.065285]  ? update_cfs_rq_load_avg+0x225/0x23a
[   20.070539]  ? update_load_avg+0x1a4/0x31e
[   20.075113]  ? pick_next_task_fair+0x360/0x381
[   20.080077]  ? finish_task_switch+0xfd/0x18d
[   20.084846]  ? __schedule+0x3e7/0x484
[   20.088935]  ? intel_atomic_commit+0x3ff/0x404
[   20.093899]  ? drm_mode_setcrtc+0x3d2/0x51b
[   20.098572]  ? avc_has_extended_perms+0x49/0x318
[   20.103728]  ? drm_ioctl+0x28b/0x31f
[   20.107721]  ? drm_crtc_check_viewport+0x8d/0x8d
[   20.112879]  ? do_vfs_ioctl+0x3a7/0x56f
[   20.117163]  ? do_syscall_64+0x59/0x68
[   20.121350]  ? entry_SYSCALL64_slow_path+0x25/0x25
[   20.126700] Code: 92 f9 ff ff 49 89 c4 4d 85 e4 74 15 48 c7 c7 bf b9 95 81 31 c0 48 8b 34 24 4c 89 e2 e8 1e 7c 06 00 4c 89 64 24 10 e9 e5 00 00 00 <4c> 8b 23 83 7c 24 50 00 74 13 4c 8b ac 24 98 00 00 00 4d 85 ed 
[   20.147848] RIP: show_trace_log_lvl+0x113/0x244 RSP: ffffc9000057f430
[   20.155045] ---[ end trace 1a54997dba9c57b5 ]---
[   20.160202] Kernel panic - not syncing: Fatal exception
[   20.166046] Kernel Offset: disabled
[   20.169943] ACPI MEMORY or I/O RESET_REG.

The issue occurs during the stack dump generated by WARN_ON().

The crash does not occur with a kernel built with gcc.
 

Comment 1 by mka@chromium.org, Jun 30 2017

Cc: llozano@chromium.org manojgupta@chromium.org
Owner: mka@chromium.org
This patch causes a crash in dump_stack() (also with gcc):

commit 1959a60182f48879635812a03a99c02231ea8677
Author: Andy Lutomirski <luto@kernel.org>
Date:   Thu Sep 15 22:45:45 2016 -0700

    x86/dumpstack: Pin the target stack when dumping it
    
    Specifically, pin the stack in save_stack_trace_tsk() and
    show_trace_log_lvl().
    
    This will prevent a crash if the target task dies before or while
    dumping its stack once we start freeing task stacks early.


However this is fixed again by:

commit 81539169f283329fd8bc58457cc15754f683ba69 
Author: Josh Poimboeuf <jpoimboe@redhat.com>
Date:   Fri Sep 16 08:05:20 2016 -0500

    x86/dumpstack: Remove NULL task pointer convention
    
    show_stack_log_lvl() and friends allow a NULL pointer for the
    task_struct to indicate the current task.  This creates confusion and
    can cause sneaky bugs.
    
    Instead require the caller to pass 'current' directly.
    
    This only changes the internal workings of the dumpstack code.  The
    dump_trace() and show_stack() interfaces still allow a NULL task
    pointer.  Those interfaces should also probably be fixed as well.


Continue bisecting to find the patch that introduces the issue.

Comment 2 by mka@chromium.org, Jun 30 2017

The problem was introduced by this commit added in v4.9:

commit e18bcccd1a4ecb41e99678e002ef833586185bf1
Author: Josh Poimboeuf <jpoimboe@redhat.com>
Date:   Fri Sep 16 14:18:16 2016 -0500

    x86/dumpstack: Convert show_trace_log_lvl() to use the new unwinder
    
    Convert show_trace_log_lvl() to use the new unwinder.  dump_trace() has
    been deprecated.
    
    show_trace_log_lvl() is special compared to other users of the unwinder.
    It's the only place where both reliable *and* unreliable addresses are
    needed.  With frame pointers enabled, most callers of the unwinder don't
    want to know about unreliable addresses.  But in this case, when we're
    dumping the stack to the console because something presumably went
    wrong, the unreliable addresses are useful:
    
    - They show stale data on the stack which can provide useful clues.
    
    - If something goes wrong with the unwinder, or if frame pointers are
      corrupt or missing, all the stack addresses still get shown.
    
    So in order to show all addresses on the stack, and at the same time
    figure out which addresses are reliable, we have to do the scanning and
    the unwinding in parallel.
    
    The scanning is done with the help of get_stack_info() to traverse the
    stacks.  The unwinding is done separately by the new unwinder.
    
    In theory we could simplify show_trace_log_lvl() by instead pushing some
    of this logic into the unwind code.  But then we would need some kind of
    "fake" frame logic in the unwinder which would add a lot of complexity
    and wouldn't be worth it in order to support only one user.
    
    Another benefit of this approach is that once we have a DWARF unwinder,
    we should be able to just plug it in with minimal impact to this code.
    
    Another change here is that callers of show_trace_log_lvl() don't need
    to provide the 'bp' argument.  The unwinder already finds the relevant
    frame pointer by unwinding until it reaches the first frame after the
    provided stack pointer.

When the issue occurs show_trace_log_lvl() sees the stack aligned at an odd boundary:

[    3.375630] MKA: stack_info.end = ffffc900006cc000
...
[    3.679776] MKA: stack = ffffc900006cbfee
[    3.679777] MKA: stack = ffffc900006cbff6
[    3.679777] MKA: stack = ffffc900006cbffe
[    3.679783] BUG: stack guard page was hit at ffffc900006cc000 (stack is ffffc900006c8000..ffffc900006cbfff)

The inner loop increments the stack pointer and dereferences it, until reaching the end of the stack:

for (; stack < stack_info.end; stack++) {
  ...
  unsigned long addr = READ_ONCE_NOCHECK(*stack);


In the above case 'stack' holds the address ffffc900006cbffe and the stack ends at ffffc900006ccfff. The read of 8 bytes from 'stack' results in hitting the guard page.

Still need to understand why the function uses these odd addresses.

Comment 3 by mka@chromium.org, Jul 6 2017

The stack pointer was already unaligned prior to this change, the loop that increments the pointer just exposes it.

The following commit introduced the function get_stack_pointer():

commit 4b8afafbe743be1a81c96ddcd75b19c534d5e262
Author: Josh Poimboeuf <jpoimboe@redhat.com>
Date:   Wed Aug 24 11:50:17 2016 -0500

    x86/dumpstack: Add get_stack_pointer() and get_frame_pointer()
    
    The various functions involved in dumping the stack all do similar
    things with regard to getting the stack pointer and the frame pointer
    based on the regs and task arguments.  Create helper functions to
    do that instead.


This function calls the intrinsic __builtin_frame_address(), which returns the unaligned value:

http://elixir.free-electrons.com/linux/v4.9.36/source/arch/x86/include/asm/stacktrace.h#L75

Some traces with register dump, sp (current) is the value returned by get_stack_pointer():

clang:

[   63.001536] MKA: show_stack: sp (param) =           (null)
[   63.001538] MKA: __builtin_frame_address (task->thread.sp = ffffc9000072fd60)
[   63.001539] MKA: show_stack: sp (current) = ffffc9000072fc94
[   63.001542] CPU: 1 PID: 617 Comm: powerd Not tainted 4.8.0-rc7-00134-gfd9c46b8a09c-dirty #42
[   63.031384] Hardware name: GOOGLE Squawks, BIOS Google_Squawks.5216.152.76 03/04/2016
[   63.040137] task: ffff88007444e000 task.stack: ffffc9000072c000
[   63.046752] RIP: 0033:[<00007f36442fe66d>]  [<00007f36442fe66d>] 0x7f36442fe66d
[   63.054920] RSP: 002b:00007fffb2c319d0  EFLAGS: 00000293
[   63.060855] RAX: ffffffffffffffda RBX: 00000000ffffffff RCX: 00007f36442fe66d
[   63.068832] RDX: 0000000000000004 RSI: 00005566dc282c78 RDI: 0000000000000012
[   63.076807] RBP: 00007fffb2c31a30 R08: 0000000000000001 R09: 00005566dc290dc0
[   63.084773] R10: 0000000000000030 R11: 0000000000000293 R12: 0000000000000004
[   63.092747] R13: 00005566dc282c78 R14: 0000000000000004 R15: 0000000000000012
[   63.100724] FS:  00007f3643178740(0000) GS:ffff88007ad00000(0000) knlGS:0000000000000000
[   63.109768] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   63.116188] CR2: 00007f1a0e534000 CR3: 000000007464c000 CR4: 00000000001006e


gcc:

[  350.273513] MKA: show_stack: sp (param) =           (null)
[  350.273516] MKA: __builtin_frame_address (task->thread.sp = ffffc9000062fd58)
[  350.273518] MKA: show_stack: sp (current) = ffffc9000062fce0
[  350.273523] CPU: 0 PID: 599 Comm: powerd Not tainted 4.8.0-rc7-00134-gfd9c46b8a09c-dirty #41
[  350.303372] Hardware name: GOOGLE Squawks, BIOS Google_Squawks.5216.152.76 03/04/2016
[  350.312127] task: ffff8800744b4800 task.stack: ffffc9000062c000
[  350.318745] RIP: 0033:[<00007f3fa420666d>]  [<00007f3fa420666d>] 0x7f3fa420666d
[  350.326930] RSP: 002b:00007ffe00b058c0  EFLAGS: 00000293
[  350.332867] RAX: ffffffffffffffda RBX: 00000000ffffffff RCX: 00007f3fa420666d
[  350.340844] RDX: 0000000000000004 RSI: 000055c7baeff8a8 RDI: 0000000000000012
[  350.348821] RBP: 00007ffe00b05920 R08: 0000000000000000 R09: 000055c7baf145e0
[  350.356798] R10: 0000000000000030 R11: 0000000000000293 R12: 0000000000000004
[  350.364774] R13: 000055c7baeff8a8 R14: 0000000000000004 R15: 0000000000000012
[  350.372754] FS:  00007f3fa3080740(0000) GS:ffff88007ac00000(0000) knlGS:0000000000000000
[  350.381799] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  350.388222] CR2: 00007f0cf5fa13b0 CR3: 0000000075f10000 CR4: 00000000001006f0

Comment 4 by mka@chromium.org, Jul 6 2017

Owner: manojgupta@chromium.org
Status: Assigned (was: Unconfirmed)
Manoj, could you dig up the implementation of __builtin_frame_address() for clang? The source code in combination with the register dump might help to shed some more light on the issue.
Matthias,
I tried to write a simple function that calls __builtin_frame_address() and both gcc and clang generated same code. 

$ cat frame_address.c
void* get_address()
{
    return __builtin_frame_address(0);
}
$ x86_64-cros-linux-gnu-clang -c -O2 -fno-omit-frame-pointer frame_address.c
$ objdump -d frame_address.o
0000000000000000 <get_address>:
   0:	55                   	push   %rbp
   1:	48 89 e5             	mov    %rsp,%rbp
   4:	48 89 e8             	mov    %rbp,%rax
   7:	5d                   	pop    %rbp
   8:	c3                   	retq

We would have to dig into the get_frame_pointer()/get_stack_pointer() function call sites. get_frame_pointer()/get_stack_pointer() calls are expected to be inlined and should not manipulate frame address. 

Comment 6 by mka@chromium.org, Jul 7 2017

Thanks Manoj,

this is the code generated for the first part of show_stack():

ffffffff810197c1 <show_stack>:
{
        printk("%sCall Trace:\n", log_lvl);
        dump_trace(task, regs, stack, bp, &print_trace_ops, log_lvl);
}

void show_stack(struct task_struct *task, unsigned long *sp)
ffffffff810197c1:       e8 4a 73 63 00          callq  ffffffff81650b10 <__fentry__>
ffffffff810197c6:       48 89 f0                mov    %rsi,%rax
{
        unsigned long bp = 0;

        task = task ? : current;
ffffffff810197c9:       48 85 ff                test   %rdi,%rdi
ffffffff810197cc:       75 09                   jne    ffffffff810197d7 <show_stack+0x16>

DECLARE_PER_CPU(struct task_struct *, current_task);

static __always_inline struct task_struct *get_current(void)
{
        return this_cpu_read_stable(current_task);
ffffffff810197ce:       65 48 8b 3c 25 c0 c3    mov    %gs:0xc3c0,%rdi
ffffffff810197d5:       00 00 
ffffffff810197d7:       55                      push   %rbp
ffffffff810197d8:       48 89 e5                mov    %rsp,%rbp

        /*
         * Stack frames below this one aren't interesting.  Don't show them
         * if we're printing for %current.
         */
        if (!sp && task == current) {
ffffffff810197db:       48 83 ec 02             sub    $0x2,%rsp
ffffffff810197df:       48 85 c0                test   %rax,%rax
ffffffff810197e2:       74 04                   je     ffffffff810197e8 <show_stack+0x27>
ffffffff810197e4:       31 c9                   xor    %ecx,%ecx
ffffffff810197e6:       eb 1b                   jmp    ffffffff81019803 <show_stack+0x42>
ffffffff810197e8:       65 48 8b 0c 25 c0 c3    mov    %gs:0xc3c0,%rcx
ffffffff810197ef:       00 00 
ffffffff810197f1:       31 c0                   xor    %eax,%eax
ffffffff810197f3:       48 39 cf                cmp    %rcx,%rdi
ffffffff810197f6:       b9 00 00 00 00          mov    $0x0,%ecx
ffffffff810197fb:       75 06                   jne    ffffffff81019803 <show_stack+0x42>
ffffffff810197fd:       48 89 e8                mov    %rbp,%rax
ffffffff81019800:       48 89 e9                mov    %rbp,%rcx
                sp = get_stack_pointer(current, NULL);
                bp = (unsigned long)get_frame_pointer(current, NULL);
        }


I single stepped through the code, which gives a more accurate picture than the register dumps. The address in rbp is aligned when show_stack() is entered, it is this instruction within get_current() that writes the unaligned address by assigning rbp to rsp:

ffffffff810197d8:       48 89 e5                mov    %rsp,%rbp

rsp is already unaligned when show_stack() is entered, which I think shouldn't be the case.

I verified that -mstack-alignment=3 is set, to make sure this is not another instance of  Issue 729743 . 

Comment 7 by mka@chromium.org, Jul 11 2017

Owner: mka@chromium.org

Comment 8 by mka@chromium.org, Jul 11 2017

This is caused by the fix for  Issue 729743 . The gcc option to specify the stack alignment (-mpreferred-stack-boundary=n) interprets the argument as 2^n, however the clang option -mstack-alignment=n uses the specified value n as alignment.

Apparently I was unlucky enough that the value of 3 aligned the stack properly for the specific problem under investigation :/

With -mstack-alignment=8 rsp and rbp are aligned at an 8-byte boundary in show_stack() and a correct backtrace is printed.
Great that you found it. It is indeed very surprising to me that clang uses n as alignment and not 2^n.
wow, that is pretty confusing!

I think we need to file a bug agains LLVM for at least clarifying in the doc and  support the GCC option directly...
Project Member

Comment 11 by bugdroid1@chromium.org, Jul 19 2017

Labels: merge-merged-chromeos-4.4
The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/third_party/kernel/+/0560b3e764bdda129600c23da3b095ed70c625f1

commit 0560b3e764bdda129600c23da3b095ed70c625f1
Author: Matthias Kaehlcke <mka@chromium.org>
Date: Wed Jul 19 23:27:01 2017

FROMGIT: x86/build: Fix stack alignment for CLang

Commit:

  d77698df39a5 ("x86/build: Specify stack alignment for clang")

intended to use the same stack alignment for clang as with gcc.

The two compilers use different options to configure the stack alignment
(gcc: -mpreferred-stack-boundary=n, clang: -mstack-alignment=n).

The above commit assumes that the clang option uses the same parameter
type as gcc, i.e. that the alignment is specified as 2^n. However clang
interprets the value of this option literally to use an alignment of n,
in consequence the stack remains misaligned.

Change the values used with -mstack-alignment to be the actual alignment
instead of a power of two.

BUG=chromium:702741,  chromium:738553 
TEST=build with clang for squawks and boot

Signed-off-by: Matthias Kaehlcke <mka@chromium.org>
Cc: Arnd Bergmann <arnd@arndb.de>
Cc: Bernhard.Rosenkranzer@linaro.org
Cc: Greg Hackmann <ghackmann@google.com>
Cc: Kees Cook <keescook@chromium.org>
Cc: Linus Torvalds <torvalds@linux-foundation.org>
Cc: Masahiro Yamada <yamada.masahiro@socionext.com>
Cc: Michael Davidson <md@google.com>
Cc: Michal Marek <mmarek@suse.com>
Cc: Nick Desaulniers <ndesaulniers@google.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephen Hines <srhines@google.com>
Cc: Thomas Gleixner <tglx@linutronix.de>
Cc: dianders@chromium.org
Cc: linux-kbuild@vger.kernel.org
Link: http://lkml.kernel.org/r/20170711212940.101416-1-mka@chromium.org
Signed-off-by: Ingo Molnar <mingo@kernel.org>
(cherry picked from git.kernel.org tip/master commit
79e6b917e69a34d45e83e72f1e9bb7487d5f5832)

Change-Id: I50bb33d4b131811043e9c81b5e168a82c840e608
Reviewed-on: https://chromium-review.googlesource.com/576256
Commit-Ready: Matthias Kaehlcke <mka@chromium.org>
Tested-by: Matthias Kaehlcke <mka@chromium.org>
Reviewed-by: Guenter Roeck <groeck@chromium.org>

[modify] https://crrev.com/0560b3e764bdda129600c23da3b095ed70c625f1/arch/x86/Makefile

Sign in to add a comment