linux-kernel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
From: Dmitry Vyukov <dvyukov@google.com>
To: Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com>
Cc: Fengguang Wu <fengguang.wu@intel.com>,
	LKML <linux-kernel@vger.kernel.org>,
	Petr Mladek <pmladek@suse.com>,
	Sergey Senozhatsky <sergey.senozhatsky@gmail.com>,
	Steven Rostedt <rostedt@goodmis.org>,
	Linus Torvalds <torvalds@linux-foundation.org>,
	Ingo Molnar <mingo@kernel.org>,
	Aleksey Makarov <aleksey.makarov@linaro.org>,
	Nicolas Pitre <nicolas.pitre@linaro.org>,
	Nikitas Angelinas <nikitas.angelinas@gmail.com>, LKP <lkp@01.org>,
	kasan-dev <kasan-dev@googlegroups.com>
Subject: Re: [ 0.003333] BUG: KASAN: use-after-scope in console_unlock+0x605/0xcc0
Date: Thu, 30 Nov 2017 09:16:17 +0100	[thread overview]
Message-ID: <CACT4Y+amQZApke6MneeK0tax=MzDbj5bce6r4MuSf8PHpzeaoA@mail.gmail.com> (raw)
In-Reply-To: <20171130064712.GA488@jagdpanzerIV>

On Thu, Nov 30, 2017 at 7:47 AM, Sergey Senozhatsky
<sergey.senozhatsky.work@gmail.com> wrote:
> Hi,
>
> On (11/30/17 10:26), Fengguang Wu wrote:
>> FYI this happens in mainline kernel v4.15-rc1 .
>> It shows up after v4.14 . Bisect is on the way.
>
> hm, printk saw no changes between 4.14 and 4.15
>
>
>> It occurs in 4 out of 4 boots.
>>
>> [    0.003333]        RCU callback double-/use-after-free debug enabled.
>> [    0.003333]        RCU CPU stall warnings timeout set to 100 (rcu_cpu_stall_timeout).
>> [    0.003333]        Tasks RCU enabled.
>> [    0.003333] NR_IRQS: 4352, nr_irqs: 48, preallocated irqs: 16
>> [    0.003333] ==================================================================
>> [    0.003333] BUG: KASAN: use-after-scope in console_unlock+0x605/0xcc0:
>>                                               atomic_read at arch/x86/include/asm/atomic.h:27
>>                                                (inlined by) static_key_count at include/linux/jump_label.h:191
>>                                                (inlined by) static_key_false at include/linux/jump_label.h:201
>>                                                (inlined by) trace_console_rcuidle at include/trace/events/printk.h:10
>>                                                (inlined by) call_console_drivers at kernel/printk/printk.c:1556
>>                                                (inlined by) console_unlock at kernel/printk/printk.c:2233
>> [    0.003333] Write of size 4 at addr ffffffff83607aa0 by task swapper/0
>> [    0.003333]
>> [    0.003333] CPU: 0 PID: 0 Comm: swapper Not tainted 4.15.0-rc1 #1
>> [    0.003333] Call Trace:
>> [    0.003333]  ? print_address_description+0x4f/0x3c0:
>>                                               print_address_description at mm/kasan/report.c:253
>> [    0.003333]  ? console_unlock+0x605/0xcc0:
>>                                               atomic_read at arch/x86/include/asm/atomic.h:27
>>                                                (inlined by) static_key_count at include/linux/jump_label.h:191
>>                                                (inlined by) static_key_false at include/linux/jump_label.h:201
>>                                                (inlined by) trace_console_rcuidle at include/trace/events/printk.h:10
>>                                                (inlined by) call_console_drivers at kernel/printk/printk.c:1556
>>                                                (inlined by) console_unlock at kernel/printk/printk.c:2233
>
> so KASAN didn't like atomic_read(&key->enabled) from static_key_count()?
> "Write of size 4"...
>
>
>> [    0.003333]  ? kasan_report+0x304/0x390:
>>                                               kasan_report_error at mm/kasan/report.c:352
>>                                                (inlined by) kasan_report at mm/kasan/report.c:409
>> [    0.003333]  ? console_unlock+0x605/0xcc0:
>>                                               atomic_read at arch/x86/include/asm/atomic.h:27
>>                                                (inlined by) static_key_count at include/linux/jump_label.h:191
>>                                                (inlined by) static_key_false at include/linux/jump_label.h:201
>>                                                (inlined by) trace_console_rcuidle at include/trace/events/printk.h:10
>>                                                (inlined by) call_console_drivers at kernel/printk/printk.c:1556
>>                                                (inlined by) console_unlock at kernel/printk/printk.c:2233
>> [    0.003333]  ? wake_up_klogd+0x180/0x180:
>>                                               console_unlock at kernel/printk/printk.c:2138
>> [    0.003333]  ? _raw_spin_unlock_irqrestore+0xcf/0xf0:
>>                                               __raw_spin_unlock_irqrestore at include/linux/spinlock_api_smp.h:161
>>                                                (inlined by) _raw_spin_unlock_irqrestore at kernel/locking/spinlock.c:191
>> [    0.003333]  ? __down_trylock_console_sem+0xf8/0x120:
>>                                               __down_trylock_console_sem at kernel/printk/printk.c:234
>> [    0.003333]  ? __down_trylock_console_sem+0x106/0x120:
>>                                               __down_trylock_console_sem at kernel/printk/printk.c:235
>> [    0.003333]  ? vprintk_emit+0x63e/0x6f0:
>>                                               vprintk_emit at kernel/printk/printk.c:1757
>> [    0.003333]  ? vprintk_func+0x11e/0x130:
>>                                               vprintk_func at kernel/printk/printk_safe.c:379
>> [    0.003333]  ? printk+0xaf/0xcf:
>>                                               printk at kernel/printk/printk.c:1824
>> [    0.003333]  ? show_regs_print_info+0x40/0x40:
>>                                               printk at kernel/printk/printk.c:1824
>> [    0.003333]  ? __flush_tlb_all+0x1e/0x31:
>>                                               __flush_tlb_global at arch/x86/include/asm/paravirt.h:298
>>                                                (inlined by) __flush_tlb_all at arch/x86/include/asm/tlbflush.h:293
>> [    0.003333]  ? native_flush_tlb_global+0x5/0xa0:
>>                                               native_flush_tlb_global at arch/x86/kernel/paravirt.c:199
>> [    0.003333]  ? kasan_init+0x276/0x306:
>>                                               kasan_init at arch/x86/mm/kasan_init_64.c:349
>> [    0.003333]  ? setup_arch+0x1bb0/0x1cad:
>>                                               setup_arch at arch/x86/kernel/setup.c:1236
>> [    0.003333]  ? reserve_standard_io_resources+0x88/0x88:
>>                                               setup_arch at arch/x86/kernel/setup.c:829
>> [    0.003333]  ? vprintk_emit+0x6dc/0x6f0:
>>                                               vprintk_emit at kernel/printk/printk.c:1761
>> [    0.003333]  ? vprintk_func+0x125/0x130:
>>                                               vprintk_func at kernel/printk/printk_safe.c:380
>> [    0.003333]  ? printk+0xaf/0xcf:
>>                                               printk at kernel/printk/printk.c:1824
>> [    0.003333]  ? show_regs_print_info+0x40/0x40:
>>                                               printk at kernel/printk/printk.c:1824
>> [    0.003333]  ? trace_hardirqs_on+0x220/0x220:
>>                                               trace_hardirqs_off at kernel/trace/trace_irqsoff.c:799
>> [    0.003333]  ? __early_make_pgtable+0x2a5/0x308:
>>                                               __early_make_pgtable at arch/x86/kernel/head64.c:251
>> [    0.003333]  ? boot_cpu_init+0x16/0x56:
>>                                               set_bit at arch/x86/include/asm/bitops.h:76
>>                                                (inlined by) cpumask_set_cpu at include/linux/cpumask.h:297
>>                                                (inlined by) set_cpu_online at include/linux/cpumask.h:799
>>                                                (inlined by) boot_cpu_init at kernel/cpu.c:2012
>> [    0.003333]  ? start_kernel+0xe7/0x8cd:
>>                                               add_latent_entropy at include/linux/random.h:26
>>                                                (inlined by) start_kernel at init/main.c:535
>> [    0.003333]  ? thread_stack_cache_init+0x37/0x37
>> [    0.003333]  ? x86_cpuid_vendor+0xbe/0xd0:
>>                                               x86_cpuid_vendor at arch/x86/include/asm/microcode.h:125
>> [    0.003333]  ? x86_family+0x2f/0x40:
>>                                               x86_family at arch/x86/lib/cpu.c:14
>> [    0.003333]  ? load_ucode_bsp+0x3c4/0x46f:
>>                                               load_ucode_bsp at arch/x86/kernel/cpu/microcode/core.c:189
>> [    0.003333]  ? x86_early_init_platform_quirks+0x146/0x1a1:
>>                                               x86_early_init_platform_quirks at arch/x86/kernel/platform-quirks.c:31
>> [    0.003333]  ? secondary_startup_64+0xa5/0xb0:
>>                                               secondary_startup_64 at arch/x86/kernel/head_64.S:237
>> [    0.003333]
>> [    0.003333] Memory state around the buggy address:
>> [    0.003333]  ffffffff83607980: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
>> [    0.003333]  ffffffff83607a00: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
>> [    0.003333] >ffffffff83607a80: f1 f1 f1 f1 f8 f2 f2 f2 f2 f2 f2 f2 00 f2 f2 f2
>
> to be honest, this backtrace hardly makes any sense to me.
>
> vprintk_emit()
>  reserve_standard_io_resources()
>   __flush_tlb_all()
>    vprintk_emit()
>     __down_trylock_console_sem()
>      wake_up_klogd()
>       console_unlock()
>
> I need some help here.


You can try dirty patch from here:
https://groups.google.com/d/msg/kasan-dev/iDb5bhcMBT0/55QzwWaHAwAJ
It should make KASAN print the exact variable name and frame where it
was allocated.

  reply	other threads:[~2017-11-30  8:16 UTC|newest]

Thread overview: 10+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2017-11-30  2:26 [ 0.003333] BUG: KASAN: use-after-scope in console_unlock+0x605/0xcc0 Fengguang Wu
2017-11-30  6:47 ` Sergey Senozhatsky
2017-11-30  8:16   ` Dmitry Vyukov [this message]
2017-11-30  8:29     ` Sergey Senozhatsky
2017-11-30  9:05       ` Fengguang Wu
2017-11-30 13:07       ` Andrey Ryabinin
2017-12-01  1:58         ` Sergey Senozhatsky
2017-11-30 14:30       ` Fengguang Wu
2017-11-30 14:45         ` Dmitry Vyukov
2017-12-01  1:32         ` Sergey Senozhatsky

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to='CACT4Y+amQZApke6MneeK0tax=MzDbj5bce6r4MuSf8PHpzeaoA@mail.gmail.com' \
    --to=dvyukov@google.com \
    --cc=aleksey.makarov@linaro.org \
    --cc=fengguang.wu@intel.com \
    --cc=kasan-dev@googlegroups.com \
    --cc=linux-kernel@vger.kernel.org \
    --cc=lkp@01.org \
    --cc=mingo@kernel.org \
    --cc=nicolas.pitre@linaro.org \
    --cc=nikitas.angelinas@gmail.com \
    --cc=pmladek@suse.com \
    --cc=rostedt@goodmis.org \
    --cc=sergey.senozhatsky.work@gmail.com \
    --cc=sergey.senozhatsky@gmail.com \
    --cc=torvalds@linux-foundation.org \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
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).