lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite for Android: free password hash cracker in your pocket
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-Id: <201803011906.JCI39072.NGYSNtPVOJMNt@I-love.SAKURA.ne.jp>
Date:   Thu, 1 Mar 2018 19:06:52 +0900
From:   Tetsuo Handa <from-linux-mm@...ove.SAKURA.ne.jp>
To:     dvyukov@...gle.com, sergey.senozhatsky@...il.com
Cc:     pmladek@...e.com, shun.hao@...el.com, xiyou.wangcong@...il.com,
        dave.hansen@...el.com, hannes@...xchg.org, mgorman@...e.de,
        mhocko@...nel.org, vbabka@...e.cz, peterz@...radead.org,
        torvalds@...ux-foundation.org, jack@...e.cz,
        mathieu.desnoyers@...icios.com, byungchul.park@....com,
        tj@...nel.org, pavel@....cz, rostedt@...dmis.org,
        linux-kernel@...r.kernel.org, lkp@...org,
        kasan-dev@...glegroups.com
Subject: Re: [lkp-robot] [printk] c162d5b433: BUG:KASAN:use-after-scope_in_c

Dmitry Vyukov wrote:
> Hi Shun,
> 
> The report says "job-script is attached in this email", but I don't
> see it attached. Did you forget to attach it? How can I reproduce this
> exact build?
> Could you post a symbolized report with inlines frames?
> 

Forwarded by penguin-kernel@...ove.sakura.ne.jp
----------------------- Original Message -----------------------
 From:    Tetsuo Handa <penguin-kernel@...ove.sakura.ne.jp>
 To:      Petr Mladek <pmladek@...e.com>
 Cc:      kernel test robot <shun.hao@...el.com>, Cong Wang <xiyou.wangcong@...il.com>, Dave Hansen <dave.hansen@...el.com>, Johannes Weiner <hannes@...xchg.org>, Mel Gorman <mgorman@...e.de>, Michal Hocko <mhocko@...nel.org>, Vlastimil Babka <vbabka@...e.cz>, Peter Zijlstra <peterz@...radead.org>, Linus Torvalds <torvalds@...ux-foundation.org>, Jan Kara <jack@...e.cz>, Mathieu Desnoyers <mathieu.desnoyers@...icios.com>, Byungchul Park <byungchul.park@....com>, Tejun Heo <tj@...nel.org>, Pavel Machek <pavel@....cz>, Steven Rostedt <rostedt@...dmis.org>, Sergey Senozhatsky <sergey.senozhatsky@...il.com>, LKML <linux-kernel@...r.kernel.org>, lkp@...org
 Date:    Thu, 01 Mar 2018 10:08:19 +0900
 Subject: Re: [lkp-robot] [printk]  c162d5b433: BUG:KASAN:use-after-scope_in_c
----

Petr Mladek wrote:
> I am really curious what code is proceed on the line
> console_unlock+0x185/0x960.

I can reproduce this warning with VMware environment.
Something is happening inside __asan_store1() before calling raw_spin_lock(&console_owner_lock) ?



[    0.000000] Kernel command line: BOOT_IMAGE=/boot/vmlinuz-4.14.0-12953-gc162d5b root=UUID=98df1583-260a-423a-a193-182dade5d085 ro crashkernel=256M security=none sysrq_always_enabled console=ttyS0,115200n8 console=tty0 LANG=en_US.UTF-8
[    0.000000] sysrq: sysrq always enabled.
[    0.000000] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes)
[    0.000000] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes)
[    0.000000] Memory: 3045216K/4193716K available (15633K kernel code, 6278K rwdata, 6948K rodata, 3592K init, 24228K bss, 1148500K reserved, 0K cma-reserved)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=64, Nodes=1
[    0.000000] ftrace: allocating 34522 entries in 135 pages
[    0.003333] Running RCU self tests
[    0.003333] Hierarchical RCU implementation.
[    0.003333] 	RCU event tracing is enabled.
[    0.003333] 	RCU dyntick-idle grace-period acceleration is enabled.
[    0.003333] 	RCU lockdep checking is enabled.
[    0.003333] 	Tasks RCU enabled.
[    0.003333] NR_IRQS: 4352, nr_irqs: 936, preallocated irqs: 16
[    0.003333] 	Offload RCU callbacks from CPUs: .
[    0.003333] ==================================================================
[    0.003333] BUG: KASAN: use-after-scope in console_unlock+0x185/0x960
[    0.003333] Write of size 1 at addr ffffffff828079b8 by task swapper/0
[    0.003333] 
[    0.003333] CPU: 0 PID: 0 Comm: swapper Not tainted 4.14.0-12953-gc162d5b #414
[    0.003333] Call Trace:
[    0.003333]  ? dump_stack+0x11d/0x1c5
[    0.003333]  ? printk+0xb5/0xd1
[    0.003333]  ? arch_local_irq_restore+0x17/0x17
[    0.003333]  ? do_raw_spin_unlock+0x137/0x169
[    0.003333]  ? irq_trace+0x2e/0x32
[    0.003333]  ? console_unlock+0x185/0x960
[    0.003333]  ? print_address_description+0x6e/0x23b
[    0.003333]  ? console_unlock+0x185/0x960
[    0.003333]  ? kasan_report+0x223/0x249
[    0.003333]  ? console_unlock+0x185/0x960
[    0.003333]  ? wake_up_klogd+0xdf/0xdf
[    0.003333]  ? do_raw_spin_unlock+0x145/0x169
[    0.003333]  ? do_raw_spin_trylock+0xed/0xed
[    0.003333]  ? irq_trace+0x2e/0x32
[    0.003333]  ? _raw_spin_unlock_irqrestore+0x3b/0x54
[    0.003333]  ? time_hardirqs_off+0x12/0x2d
[    0.003333]  ? arch_local_save_flags+0x7/0x8
[    0.003333]  ? trace_hardirqs_off_caller+0x127/0x139
[    0.003333]  ? irq_trace+0x2e/0x32
[    0.003333]  ? vprintk_emit+0x579/0x823
[    0.003333]  ? __down_trylock_console_sem+0x90/0xa4
[    0.003333]  ? __down_trylock_console_sem+0x9d/0xa4
[    0.003333]  ? vprintk_emit+0x7ec/0x823
[    0.003333]  ? console_unlock+0x960/0x960
[    0.003333]  ? memblock_merge_regions+0x2d/0x154
[    0.003333]  ? memblock_add_range+0x322/0x333
[    0.003333]  ? memblock_reserve+0xbb/0xe1
[    0.003333]  ? memblock_add+0xe1/0xe1
[    0.003333]  ? set_pte+0x24/0x27
[    0.003333]  ? vprintk_func+0x94/0xa5
[    0.003333]  ? printk+0xb5/0xd1
[    0.003333]  ? show_regs_print_info+0x41/0x41
[    0.003333]  ? kasan_populate_zero_shadow+0x37b/0x3f6
[    0.003333]  ? native_flush_tlb_global+0x74/0x80
[    0.003333]  ? kasan_init+0x211/0x22d
[    0.003333]  ? setup_arch+0xdfa/0xf3c
[    0.003333]  ? css_set_populated+0x79/0x79
[    0.003333]  ? reserve_standard_io_resources+0x39/0x39
[    0.003333]  ? vprintk_func+0x9d/0xa5
[    0.003333]  ? printk+0xb5/0xd1
[    0.003333]  ? show_regs_print_info+0x41/0x41
[    0.003333]  ? start_kernel+0xa2/0x515
[    0.003333]  ? mem_encrypt_init+0xa/0xa
[    0.003333]  ? x86_family+0x2e/0x33
[    0.003333]  ? load_ucode_bsp+0x58/0xec
[    0.003333]  ? secondary_startup_64+0xa5/0xb0
[    0.003333] 
[    0.003333] 
[    0.003333] Memory state around the buggy address:
[    0.003333]  ffffffff82807880: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[    0.003333]  ffffffff82807900: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[    0.003333] >ffffffff82807980: 00 00 00 f1 f1 f1 f1 f8 f2 f2 f2 f2 f2 f2 f2 01
[    0.003333]                                         ^
[    0.003333]  ffffffff82807a00: f2 f2 f2 f2 f2 f2 f2 00 f2 f2 f2 f3 f3 f3 f3 00
[    0.003333]  ffffffff82807a80: 00 00 00 00 00 00 00 00 00 00 00 00 00 f1 f1 f1
[    0.003333] ==================================================================
[    0.003333] Disabling lock debugging due to kernel taint
[    0.003333] ==================================================================
[    0.003333] BUG: KASAN: use-after-scope in console_unlock+0x185/0x960
[    0.003333] Write of size 1 at addr ffffffff828079b8 by task swapper/0
[    0.003333] 
[    0.003333] CPU: 0 PID: 0 Comm: swapper Not tainted 4.14.0-12953-gc162d5b #414
[    0.003333] Call Trace:
[    0.003333]  ? dump_stack+0x11d/0x1c5
[    0.003333]  ? printk+0xb5/0xd1
[    0.003333]  ? arch_local_irq_restore+0x17/0x17
[    0.003333]  ? do_raw_spin_unlock+0x137/0x169
[    0.003333]  ? irq_trace+0x2e/0x32
[    0.003333]  ? console_unlock+0x185/0x960
[    0.003333]  ? print_address_description+0x6e/0x23b
[    0.003333]  ? console_unlock+0x185/0x960
[    0.003333]  ? kasan_report+0x223/0x249
[    0.003333]  ? console_unlock+0x185/0x960
[    0.003333]  ? wake_up_klogd+0xdf/0xdf
[    0.003333]  ? do_raw_spin_unlock+0x145/0x169
[    0.003333]  ? do_raw_spin_trylock+0xed/0xed
[    0.003333]  ? irq_trace+0x2e/0x32
[    0.003333]  ? _raw_spin_unlock_irqrestore+0x3b/0x54
[    0.003333]  ? time_hardirqs_off+0x12/0x2d
[    0.003333]  ? arch_local_save_flags+0x7/0x8
[    0.003333]  ? trace_hardirqs_off_caller+0x127/0x139
[    0.003333]  ? irq_trace+0x2e/0x32
[    0.003333]  ? vprintk_emit+0x579/0x823
[    0.003333]  ? __down_trylock_console_sem+0x90/0xa4
[    0.003333]  ? __down_trylock_console_sem+0x9d/0xa4
[    0.003333]  ? vprintk_emit+0x7ec/0x823
[    0.003333]  ? console_unlock+0x960/0x960
[    0.003333]  ? memblock_merge_regions+0x2d/0x154
[    0.003333]  ? memblock_add_range+0x322/0x333
[    0.003333]  ? memblock_reserve+0xbb/0xe1
[    0.003333]  ? memblock_add+0xe1/0xe1
[    0.003333]  ? set_pte+0x24/0x27
[    0.003333]  ? vprintk_func+0x94/0xa5
[    0.003333]  ? printk+0xb5/0xd1
[    0.003333]  ? show_regs_print_info+0x41/0x41
[    0.003333]  ? kasan_populate_zero_shadow+0x37b/0x3f6
[    0.003333]  ? native_flush_tlb_global+0x74/0x80
[    0.003333]  ? kasan_init+0x211/0x22d
[    0.003333]  ? setup_arch+0xdfa/0xf3c
[    0.003333]  ? css_set_populated+0x79/0x79
[    0.003333]  ? reserve_standard_io_resources+0x39/0x39
[    0.003333]  ? vprintk_func+0x9d/0xa5
[    0.003333]  ? printk+0xb5/0xd1
[    0.003333]  ? show_regs_print_info+0x41/0x41
[    0.003333]  ? start_kernel+0xa2/0x515
[    0.003333]  ? mem_encrypt_init+0xa/0xa
[    0.003333]  ? x86_family+0x2e/0x33
[    0.003333]  ? load_ucode_bsp+0x58/0xec
[    0.003333]  ? secondary_startup_64+0xa5/0xb0
[    0.003333] 
[    0.003333] 
[    0.003333] Memory state around the buggy address:
[    0.003333]  ffffffff82807880: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[    0.003333]  ffffffff82807900: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[    0.003333] >ffffffff82807980: 00 00 00 f1 f1 f1 f1 f8 f2 f2 f2 f2 f2 f2 f2 01
[    0.003333]                                         ^
[    0.003333]  ffffffff82807a00: f2 f2 f2 f2 f2 f2 f2 00 f2 f2 f2 f3 f3 f3 f3 00
[    0.003333]  ffffffff82807a80: 00 00 00 00 00 00 00 00 00 00 00 00 00 f1 f1 f1
[    0.003333] ==================================================================
[    0.003333] Disabling lock debugging due to kernel taint
[    0.003333] ==================================================================



# ./scripts/faddr2line vmlinux console_unlock+0x185/0x960
console_unlock+0x185/0x960:
console_lock_spinning_disable_and_check at kernel/printk/printk.c:1600
 (inlined by) console_unlock at kernel/printk/printk.c:2386



ffffffff81190da4 <console_unlock>:
 * If there is output waiting, we wake /dev/kmsg and syslog() users.
 *
 * console_unlock(); may be called from any context.
 */
void console_unlock(void)
{
ffffffff81190da4:	e8 57 e1 da 00       	callq  ffffffff81f3ef00 <__fentry__>
ffffffff81190da9:	55                   	push   %rbp
ffffffff81190daa:	48 89 e5             	mov    %rsp,%rbp
ffffffff81190dad:	41 57                	push   %r15
ffffffff81190daf:	41 56                	push   %r14
ffffffff81190db1:	48 8d 85 f8 fe ff ff 	lea    -0x108(%rbp),%rax
ffffffff81190db8:	41 55                	push   %r13
ffffffff81190dba:	41 54                	push   %r12
ffffffff81190dbc:	53                   	push   %rbx
ffffffff81190dbd:	48 bb 00 00 00 00 00 	movabs $0xdffffc0000000000,%rbx
ffffffff81190dc4:	fc ff df 
ffffffff81190dc7:	48 c1 e8 03          	shr    $0x3,%rax
ffffffff81190dcb:	48 81 ec 20 01 00 00 	sub    $0x120,%rsp
ffffffff81190dd2:	48 89 85 d0 fe ff ff 	mov    %rax,-0x130(%rbp)
ffffffff81190dd9:	48 01 d8             	add    %rbx,%rax
ffffffff81190ddc:	48 c7 85 f8 fe ff ff 	movq   $0x41b58ab3,-0x108(%rbp)
ffffffff81190de3:	b3 8a b5 41 
ffffffff81190de7:	48 c7 85 00 ff ff ff 	movq   $0xffffffff825fb4c2,-0x100(%rbp)
ffffffff81190dee:	c2 b4 5f 82 
ffffffff81190df2:	48 c7 85 08 ff ff ff 	movq   $0xffffffff81190da4,-0xf8(%rbp)
ffffffff81190df9:	a4 0d 19 81 
ffffffff81190dfd:	c7 00 f1 f1 f1 f1    	movl   $0xf1f1f1f1,(%rax)
ffffffff81190e03:	c7 40 04 01 f2 f2 f2 	movl   $0xf2f2f201,0x4(%rax)
ffffffff81190e0a:	c7 40 08 f2 f2 f2 f2 	movl   $0xf2f2f2f2,0x8(%rax)
ffffffff81190e11:	c7 40 0c 01 f2 f2 f2 	movl   $0xf2f2f201,0xc(%rax)
ffffffff81190e18:	c7 40 10 f2 f2 f2 f2 	movl   $0xf2f2f2f2,0x10(%rax)
ffffffff81190e1f:	c7 40 14 00 f2 f2 f2 	movl   $0xf2f2f200,0x14(%rax)
ffffffff81190e26:	c7 40 18 f3 f3 f3 f3 	movl   $0xf3f3f3f3,0x18(%rax)
	static u64 seen_seq;
	unsigned long flags;
	bool wake_klogd = false;
	bool do_cond_resched, retry;

	if (console_suspended) {
ffffffff81190e2d:	e8 3f 82 08 00       	callq  ffffffff81219071 <__sanitizer_cov_trace_pc>
ffffffff81190e32:	83 3d a7 c2 14 03 00 	cmpl   $0x0,0x314c2a7(%rip)        # ffffffff842dd0e0 <console_suspended>
ffffffff81190e39:	74 0a                	je     ffffffff81190e45 <console_unlock+0xa1>
		up_console_sem();
ffffffff81190e3b:	e8 31 82 08 00       	callq  ffffffff81219071 <__sanitizer_cov_trace_pc>
ffffffff81190e40:	e9 85 08 00 00       	jmpq   ffffffff811916ca <console_unlock+0x926>
	 *
	 * console_trylock() is not able to detect the preemptive
	 * context reliably. Therefore the value must be stored before
	 * and cleared after the the "again" goto label.
	 */
	do_cond_resched = console_may_schedule;
ffffffff81190e45:	e8 27 82 08 00       	callq  ffffffff81219071 <__sanitizer_cov_trace_pc>
ffffffff81190e4a:	8b 05 b0 c0 14 03    	mov    0x314c0b0(%rip),%eax        # ffffffff842dcf00 <console_may_schedule>
{
	static char ext_text[CONSOLE_EXT_LOG_MAX];
	static char text[LOG_LINE_MAX + PREFIX_MAX];
	static u64 seen_seq;
	unsigned long flags;
	bool wake_klogd = false;
ffffffff81190e50:	45 31 ed             	xor    %r13d,%r13d
ffffffff81190e53:	48 89 9d e8 fe ff ff 	mov    %rbx,-0x118(%rbp)
	 *
	 * console_trylock() is not able to detect the preemptive
	 * context reliably. Therefore the value must be stored before
	 * and cleared after the the "again" goto label.
	 */
	do_cond_resched = console_may_schedule;
ffffffff81190e5a:	89 85 cc fe ff ff    	mov    %eax,-0x134(%rbp)
again:
	console_may_schedule = 0;
ffffffff81190e60:	e8 0c 82 08 00       	callq  ffffffff81219071 <__sanitizer_cov_trace_pc>
 * unless they're explicitly marked as being able to cope (CON_ANYTIME) don't
 * call them until this CPU is officially up.
 */
static inline int can_use_console(void)
{
	return cpu_online(raw_smp_processor_id()) || have_callable_console();
ffffffff81190e65:	65 8b 05 bc 22 e8 7e 	mov    %gs:0x7ee822bc(%rip),%eax        # 13128 <cpu_number>
	 * context reliably. Therefore the value must be stored before
	 * and cleared after the the "again" goto label.
	 */
	do_cond_resched = console_may_schedule;
again:
	console_may_schedule = 0;
ffffffff81190e6c:	c7 05 8a c0 14 03 00 	movl   $0x0,0x314c08a(%rip)        # ffffffff842dcf00 <console_may_schedule>
ffffffff81190e73:	00 00 00 
 *
 * Returns 1 if @cpu is set in @cpumask, else returns 0
 */
static inline int cpumask_test_cpu(int cpu, const struct cpumask *cpumask)
{
	return test_bit(cpumask_check(cpu), cpumask_bits((cpumask)));
ffffffff81190e76:	89 c0                	mov    %eax,%eax

static __always_inline bool variable_test_bit(long nr, volatile const unsigned long *addr)
{
	bool oldbit;

	asm volatile("bt %2,%1"
ffffffff81190e78:	48 0f a3 05 a8 ad c8 	bt     %rax,0x1c8ada8(%rip)        # ffffffff82e1bc28 <__cpu_online_mask>
ffffffff81190e7f:	01 
ffffffff81190e80:	49 c7 c6 28 bc e1 82 	mov    $0xffffffff82e1bc28,%r14
 * unless they're explicitly marked as being able to cope (CON_ANYTIME) don't
 * call them until this CPU is officially up.
 */
static inline int can_use_console(void)
{
	return cpu_online(raw_smp_processor_id()) || have_callable_console();
ffffffff81190e87:	0f 82 a3 01 00 00    	jb     ffffffff81191030 <console_unlock+0x28c>
 */
static int have_callable_console(void)
{
	struct console *con;

	for_each_console(con)
ffffffff81190e8d:	e8 df 81 08 00       	callq  ffffffff81219071 <__sanitizer_cov_trace_pc>
ffffffff81190e92:	48 8b 1d 07 c3 14 03 	mov    0x314c307(%rip),%rbx        # ffffffff842dd1a0 <console_drivers>
ffffffff81190e99:	e8 d3 81 08 00       	callq  ffffffff81219071 <__sanitizer_cov_trace_pc>
ffffffff81190e9e:	48 85 db             	test   %rbx,%rbx
ffffffff81190ea1:	0f 84 14 08 00 00    	je     ffffffff811916bb <console_unlock+0x917>
		if ((con->flags & CON_ENABLED) &&
ffffffff81190ea7:	e8 c5 81 08 00       	callq  ffffffff81219071 <__sanitizer_cov_trace_pc>
ffffffff81190eac:	48 8d 7b 40          	lea    0x40(%rbx),%rdi
ffffffff81190eb0:	e8 bd 51 1f 00       	callq  ffffffff81386072 <__asan_load2>
ffffffff81190eb5:	8b 43 40             	mov    0x40(%rbx),%eax
ffffffff81190eb8:	83 e0 14             	and    $0x14,%eax
ffffffff81190ebb:	66 83 f8 14          	cmp    $0x14,%ax
ffffffff81190ebf:	0f 84 6b 01 00 00    	je     ffffffff81191030 <console_unlock+0x28c>
 */
static int have_callable_console(void)
{
	struct console *con;

	for_each_console(con)
ffffffff81190ec5:	e8 a7 81 08 00       	callq  ffffffff81219071 <__sanitizer_cov_trace_pc>
ffffffff81190eca:	48 8d 7b 50          	lea    0x50(%rbx),%rdi
ffffffff81190ece:	e8 89 53 1f 00       	callq  ffffffff8138625c <__asan_load8>
ffffffff81190ed3:	48 8b 5b 50          	mov    0x50(%rbx),%rbx
ffffffff81190ed7:	eb c0                	jmp    ffffffff81190e99 <console_unlock+0xf5>
ffffffff81190ed9:	e8 93 81 08 00       	callq  ffffffff81219071 <__sanitizer_cov_trace_pc>
ffffffff81190ede:	65 8b 05 43 22 e8 7e 	mov    %gs:0x7ee82243(%rip),%eax        # 13128 <cpu_number>
ffffffff81190ee5:	89 c0                	mov    %eax,%eax
ffffffff81190ee7:	49 0f a3 06          	bt     %rax,(%r14)
ffffffff81190eeb:	0f 82 6c 04 00 00    	jb     ffffffff8119135d <console_unlock+0x5b9>
{
	struct console *con;

	trace_console_rcuidle(text, len);

	if (!console_drivers)
ffffffff81190ef1:	e8 7b 81 08 00       	callq  ffffffff81219071 <__sanitizer_cov_trace_pc>
ffffffff81190ef6:	48 8b 1d a3 c2 14 03 	mov    0x314c2a3(%rip),%rbx        # ffffffff842dd1a0 <console_drivers>
ffffffff81190efd:	48 85 db             	test   %rbx,%rbx
ffffffff81190f00:	0f 85 5c 05 00 00    	jne    ffffffff81191462 <console_unlock+0x6be>
ffffffff81190f06:	48 8d 9d 18 ff ff ff 	lea    -0xe8(%rbp),%rbx
ffffffff81190f0d:	4c 8d a5 58 ff ff ff 	lea    -0xa8(%rbp),%r12
		 */
		console_lock_spinning_enable();

		stop_critical_timings();	/* don't trace print latency */
		call_console_drivers(ext_text, ext_len, text, len);
		start_critical_timings();
ffffffff81190f14:	e8 58 81 08 00       	callq  ffffffff81219071 <__sanitizer_cov_trace_pc>
ffffffff81190f19:	e8 18 a2 0c 00       	callq  ffffffff8125b136 <start_critical_timings>
ffffffff81190f1e:	48 89 df             	mov    %rbx,%rdi
static int console_lock_spinning_disable_and_check(void)
{
	int waiter;

	raw_spin_lock(&console_owner_lock);
	waiter = READ_ONCE(console_waiter);
ffffffff81190f21:	49 89 df             	mov    %rbx,%r15
ffffffff81190f24:	e8 04 51 1f 00       	callq  ffffffff8138602d <__asan_store1>
ffffffff81190f29:	4c 89 e7             	mov    %r12,%rdi                              /*** console_unlock+0x185/0x960 ***/
ffffffff81190f2c:	c6 85 18 ff ff ff 00 	movb   $0x0,-0xe8(%rbp)
ffffffff81190f33:	49 c1 ef 03          	shr    $0x3,%r15
ffffffff81190f37:	e8 f1 50 1f 00       	callq  ffffffff8138602d <__asan_store1>
 */
static int console_lock_spinning_disable_and_check(void)
{
	int waiter;

	raw_spin_lock(&console_owner_lock);
ffffffff81190f3c:	48 c7 c7 e0 96 95 82 	mov    $0xffffffff829596e0,%rdi   /*** ffffffff829596e0 d console_owner_lock ***/
ffffffff81190f43:	c6 85 58 ff ff ff 00 	movb   $0x0,-0xa8(%rbp)
ffffffff81190f4a:	e8 9a bd da 00       	callq  ffffffff81f3cce9 <_raw_spin_lock>
	waiter = READ_ONCE(console_waiter);
ffffffff81190f4f:	4c 03 bd e8 fe ff ff 	add    -0x118(%rbp),%r15
ffffffff81190f56:	8a 05 c4 bb 04 03    	mov    0x304bbc4(%rip),%al        # ffffffff841dcb20 <console_waiter>
ffffffff81190f5c:	48 89 df             	mov    %rbx,%rdi
ffffffff81190f5f:	88 85 e0 fe ff ff    	mov    %al,-0x120(%rbp)
ffffffff81190f65:	41 c6 07 01          	movb   $0x1,(%r15)
ffffffff81190f69:	e8 bf 50 1f 00       	callq  ffffffff8138602d <__asan_store1>
ffffffff81190f6e:	8a 85 e0 fe ff ff    	mov    -0x120(%rbp),%al
ffffffff81190f74:	48 89 df             	mov    %rbx,%rdi
ffffffff81190f77:	88 85 18 ff ff ff    	mov    %al,-0xe8(%rbp)
ffffffff81190f7d:	e8 69 50 1f 00       	callq  ffffffff81385feb <__asan_load1>
ffffffff81190f82:	8a 85 18 ff ff ff    	mov    -0xe8(%rbp),%al
	console_owner = NULL;
	raw_spin_unlock(&console_owner_lock);
ffffffff81190f88:	48 c7 c7 e0 96 95 82 	mov    $0xffffffff829596e0,%rdi
ffffffff81190f8f:	41 c6 07 f8          	movb   $0xf8,(%r15)
{
	int waiter;

	raw_spin_lock(&console_owner_lock);
	waiter = READ_ONCE(console_waiter);
	console_owner = NULL;
ffffffff81190f93:	48 c7 05 c2 bb 04 03 	movq   $0x0,0x304bbc2(%rip)        # ffffffff841dcb60 <console_owner>
ffffffff81190f9a:	00 00 00 00 
static int console_lock_spinning_disable_and_check(void)
{
	int waiter;

	raw_spin_lock(&console_owner_lock);
	waiter = READ_ONCE(console_waiter);
ffffffff81190f9e:	88 85 e0 fe ff ff    	mov    %al,-0x120(%rbp)
	console_owner = NULL;
	raw_spin_unlock(&console_owner_lock);
ffffffff81190fa4:	e8 9b bf da 00       	callq  ffffffff81f3cf44 <_raw_spin_unlock>
ffffffff81190fa9:	48 8b 9d f0 fe ff ff 	mov    -0x110(%rbp),%rbx

	if (!waiter) {
ffffffff81190fb0:	8a 85 e0 fe ff ff    	mov    -0x120(%rbp),%al
ffffffff81190fb6:	81 e3 00 02 00 00    	and    $0x200,%ebx
ffffffff81190fbc:	84 c0                	test   %al,%al
ffffffff81190fbe:	0f 85 54 05 00 00    	jne    ffffffff81191518 <console_unlock+0x774>
		spin_release(&console_owner_dep_map, 1, _THIS_IP_);
ffffffff81190fc4:	e8 a8 80 08 00       	callq  ffffffff81219071 <__sanitizer_cov_trace_pc>
ffffffff81190fc9:	48 c7 c2 c4 0f 19 81 	mov    $0xffffffff81190fc4,%rdx
ffffffff81190fd0:	be 01 00 00 00       	mov    $0x1,%esi
ffffffff81190fd5:	48 c7 c7 60 97 95 82 	mov    $0xffffffff82959760,%rdi
ffffffff81190fdc:	e8 0d 19 fe ff       	callq  ffffffff811728ee <lock_release>
		if (console_lock_spinning_disable_and_check()) {
			printk_safe_exit_irqrestore(flags);
			return;
		}

		printk_safe_exit_irqrestore(flags);
ffffffff81190fe1:	e8 82 2d 00 00       	callq  ffffffff81193d68 <__printk_safe_exit>
ffffffff81190fe6:	48 85 db             	test   %rbx,%rbx
ffffffff81190fe9:	0f 85 d6 05 00 00    	jne    ffffffff811915c5 <console_unlock+0x821>
ffffffff81190fef:	e8 7d 80 08 00       	callq  ffffffff81219071 <__sanitizer_cov_trace_pc>
ffffffff81190ff4:	48 8b bd f0 fe ff ff 	mov    -0x110(%rbp),%rdi
ffffffff81190ffb:	e8 48 ca ff ff       	callq  ffffffff8118da48 <arch_local_irq_restore>
ffffffff81191000:	e8 42 9f fd ff       	callq  ffffffff8116af47 <trace_hardirqs_off>

		if (do_cond_resched)
ffffffff81191005:	e8 67 80 08 00       	callq  ffffffff81219071 <__sanitizer_cov_trace_pc>
ffffffff8119100a:	83 bd cc fe ff ff 00 	cmpl   $0x0,-0x134(%rbp)
ffffffff81191011:	74 1d                	je     ffffffff81191030 <console_unlock+0x28c>
			cond_resched();
ffffffff81191013:	e8 59 80 08 00       	callq  ffffffff81219071 <__sanitizer_cov_trace_pc>
ffffffff81191018:	31 d2                	xor    %edx,%edx
ffffffff8119101a:	be 5a 09 00 00       	mov    $0x95a,%esi
ffffffff8119101f:	48 c7 c7 00 65 07 82 	mov    $0xffffffff82076500,%rdi
ffffffff81191026:	e8 91 77 fa ff       	callq  ffffffff811387bc <___might_sleep>
ffffffff8119102b:	e8 43 66 da 00       	callq  ffffffff81f37673 <_cond_resched>



Forwarded by penguin-kernel@...ove.sakura.ne.jp
----------------------- Original Message -----------------------
 From:    Tetsuo Handa <penguin-kernel@...ove.sakura.ne.jp>
 To:      Petr Mladek <pmladek@...e.com>
 Cc:      kernel test robot <shun.hao@...el.com>, Cong Wang <xiyou.wangcong@...il.com>, Dave Hansen <dave.hansen@...el.com>, Johannes Weiner <hannes@...xchg.org>, Mel Gorman <mgorman@...e.de>, Michal Hocko <mhocko@...nel.org>, Vlastimil Babka <vbabka@...e.cz>, Peter Zijlstra <peterz@...radead.org>, Linus Torvalds <torvalds@...ux-foundation.org>, Jan Kara <jack@...e.cz>, Mathieu Desnoyers <mathieu.desnoyers@...icios.com>, Byungchul Park <byungchul.park@....com>, Tejun Heo <tj@...nel.org>, Pavel Machek <pavel@....cz>, Steven Rostedt <rostedt@...dmis.org>, Sergey Senozhatsky <sergey.senozhatsky@...il.com>, LKML <linux-kernel@...r.kernel.org>, lkp@...org
 Date:    Thu, 01 Mar 2018 12:26:15 +0900
 Subject: Re: [lkp-robot] [printk]  c162d5b433: BUG:KASAN:use-after-scope_in_c
----

Tetsuo Handa wrote:
> Petr Mladek wrote:
> > I am really curious what code is proceed on the line
> > console_unlock+0x185/0x960.
> 
> I can reproduce this warning with VMware environment.
> Something is happening inside __asan_store1() before calling raw_spin_lock(&console_owner_lock) ?
> 

Interesting thing is that as of commit 97ace515f01439d4 on linux.git, there is no
such __asan_store1() before calling raw_spin_lock(&console_owner_lock) and hence
cannot reproduce this warning. Maybe a KASAN bug as of commit c162d5b4338d72de ?



ffffffff8115d3a1 <console_unlock>:
 * If there is output waiting, we wake /dev/kmsg and syslog() users.
 *
 * console_unlock(); may be called from any context.
 */
void console_unlock(void)
{
ffffffff8115d3a1:       e8 5a 44 ca 00          callq  ffffffff81e01800 <__fentry__>
ffffffff8115d3a6:       41 57                   push   %r15
ffffffff8115d3a8:       41 56                   push   %r14
ffffffff8115d3aa:       41 55                   push   %r13
ffffffff8115d3ac:       41 54                   push   %r12
ffffffff8115d3ae:       55                      push   %rbp
ffffffff8115d3af:       53                      push   %rbx
ffffffff8115d3b0:       48 83 ec 28             sub    $0x28,%rsp
        static u64 seen_seq;
        unsigned long flags;
        bool wake_klogd = false;
        bool do_cond_resched, retry;

        if (console_suspended) {
ffffffff8115d3b4:       e8 6e e6 06 00          callq  ffffffff811cba27 <__sanitizer_cov_trace_pc>
ffffffff8115d3b9:       83 3d 60 e1 34 03 00    cmpl   $0x0,0x334e160(%rip)        # ffffffff844ab520 <console_suspended>
ffffffff8115d3c0:       74 0a                   je     ffffffff8115d3cc <console_unlock+0x2b>
                up_console_sem();
ffffffff8115d3c2:       e8 60 e6 06 00          callq  ffffffff811cba27 <__sanitizer_cov_trace_pc>
ffffffff8115d3c7:       e9 4d 07 00 00          jmpq   ffffffff8115db19 <console_unlock+0x778>
         *
         * console_trylock() is not able to detect the preemptive
         * context reliably. Therefore the value must be stored before
         * and cleared after the the "again" goto label.
         */
        do_cond_resched = console_may_schedule;
ffffffff8115d3cc:       e8 56 e6 06 00          callq  ffffffff811cba27 <__sanitizer_cov_trace_pc>
ffffffff8115d3d1:       8b 05 69 df 34 03       mov    0x334df69(%rip),%eax        # ffffffff844ab340 <console_may_schedule>
{
        static char ext_text[CONSOLE_EXT_LOG_MAX];
        static char text[LOG_LINE_MAX + PREFIX_MAX];
        static u64 seen_seq;
        unsigned long flags;
        bool wake_klogd = false;
ffffffff8115d3d7:       45 31 f6                xor    %r14d,%r14d

static __always_inline bool variable_test_bit(long nr, volatile const unsigned long *addr)
{
        bool oldbit;

        asm volatile("bt %2,%1"
ffffffff8115d3da:       49 c7 c5 e8 92 01 83    mov    $0xffffffff830192e8,%r13
         *
         * console_trylock() is not able to detect the preemptive
         * context reliably. Therefore the value must be stored before
         * and cleared after the the "again" goto label.
         */
        do_cond_resched = console_may_schedule;
ffffffff8115d3e1:       89 44 24 18             mov    %eax,0x18(%rsp)
again:
        console_may_schedule = 0;
ffffffff8115d3e5:       e8 3d e6 06 00          callq  ffffffff811cba27 <__sanitizer_cov_trace_pc>
 * unless they're explicitly marked as being able to cope (CON_ANYTIME) don't
 * call them until this CPU is officially up.
 */
static inline int can_use_console(void)
{
        return cpu_online(raw_smp_processor_id()) || have_callable_console();
ffffffff8115d3ea:       65 8b 05 3f ad eb 7e    mov    %gs:0x7eebad3f(%rip),%eax        # 18130 <cpu_number>
         * context reliably. Therefore the value must be stored before
         * and cleared after the the "again" goto label.
         */
        do_cond_resched = console_may_schedule;
again:
        console_may_schedule = 0;
ffffffff8115d3f1:       c7 05 45 df 34 03 00    movl   $0x0,0x334df45(%rip)        # ffffffff844ab340 <console_may_schedule>
ffffffff8115d3f8:       00 00 00
 *
 * Returns 1 if @cpu is set in @cpumask, else returns 0
 */
static inline int cpumask_test_cpu(int cpu, const struct cpumask *cpumask)
{
        return test_bit(cpumask_check(cpu), cpumask_bits((cpumask)));
ffffffff8115d3fb:       89 c0                   mov    %eax,%eax
ffffffff8115d3fd:       49 0f a3 45 00          bt     %rax,0x0(%r13)
 * unless they're explicitly marked as being able to cope (CON_ANYTIME) don't
 * call them until this CPU is officially up.
 */
static inline int can_use_console(void)
{
        return cpu_online(raw_smp_processor_id()) || have_callable_console();
ffffffff8115d402:       0f 82 26 01 00 00       jb     ffffffff8115d52e <console_unlock+0x18d>
 */
static int have_callable_console(void)
{
        struct console *con;

        for_each_console(con)
ffffffff8115d408:       e8 1a e6 06 00          callq  ffffffff811cba27 <__sanitizer_cov_trace_pc>
ffffffff8115d40d:       48 8b 1d cc e1 34 03    mov    0x334e1cc(%rip),%rbx        # ffffffff844ab5e0 <console_drivers>
ffffffff8115d414:       e8 0e e6 06 00          callq  ffffffff811cba27 <__sanitizer_cov_trace_pc>
ffffffff8115d419:       48 85 db                test   %rbx,%rbx
ffffffff8115d41c:       0f 84 e8 06 00 00       je     ffffffff8115db0a <console_unlock+0x769>
                if ((con->flags & CON_ENABLED) &&
ffffffff8115d422:       e8 00 e6 06 00          callq  ffffffff811cba27 <__sanitizer_cov_trace_pc>
ffffffff8115d427:       48 8d 7b 40             lea    0x40(%rbx),%rdi
ffffffff8115d42b:       e8 4c 1c 1a 00          callq  ffffffff812ff07c <__asan_load2>
ffffffff8115d430:       8b 43 40                mov    0x40(%rbx),%eax
ffffffff8115d433:       83 e0 14                and    $0x14,%eax
ffffffff8115d436:       66 83 f8 14             cmp    $0x14,%ax
ffffffff8115d43a:       0f 84 ee 00 00 00       je     ffffffff8115d52e <console_unlock+0x18d>
 */
static int have_callable_console(void)
{
        struct console *con;

        for_each_console(con)
ffffffff8115d440:       e8 e2 e5 06 00          callq  ffffffff811cba27 <__sanitizer_cov_trace_pc>
ffffffff8115d445:       48 8d 7b 50             lea    0x50(%rbx),%rdi
ffffffff8115d449:       e8 18 1e 1a 00          callq  ffffffff812ff266 <__asan_load8>
ffffffff8115d44e:       48 8b 5b 50             mov    0x50(%rbx),%rbx
ffffffff8115d452:       eb c0                   jmp    ffffffff8115d414 <console_unlock+0x73>
ffffffff8115d454:       e8 ce e5 06 00          callq  ffffffff811cba27 <__sanitizer_cov_trace_pc>
ffffffff8115d459:       65 8b 05 d0 ac eb 7e    mov    %gs:0x7eebacd0(%rip),%eax        # 18130 <cpu_number>
ffffffff8115d460:       89 c0                   mov    %eax,%eax
ffffffff8115d462:       49 0f a3 45 00          bt     %rax,0x0(%r13)
ffffffff8115d467:       0f 82 b1 03 00 00       jb     ffffffff8115d81e <console_unlock+0x47d>
{
        struct console *con;

        trace_console_rcuidle(text, len);

        if (!console_drivers)
ffffffff8115d46d:       e8 b5 e5 06 00          callq  ffffffff811cba27 <__sanitizer_cov_trace_pc>
ffffffff8115d472:       48 8b 1d 67 e1 34 03    mov    0x334e167(%rip),%rbx        # ffffffff844ab5e0 <console_drivers>
ffffffff8115d479:       48 85 db                test   %rbx,%rbx
ffffffff8115d47c:       0f 85 63 04 00 00       jne    ffffffff8115d8e5 <console_unlock+0x544>
                 */
                console_lock_spinning_enable();

                stop_critical_timings();        /* don't trace print latency */
                call_console_drivers(ext_text, ext_len, text, len);
                start_critical_timings();
ffffffff8115d482:       e8 a0 e5 06 00          callq  ffffffff811cba27 <__sanitizer_cov_trace_pc>
ffffffff8115d487:       e8 ce 49 0a 00          callq  ffffffff81201e5a <start_critical_timings>
 */
static int console_lock_spinning_disable_and_check(void)
{
        int waiter;

        raw_spin_lock(&console_owner_lock);
ffffffff8115d48c:       48 c7 c7 00 38 b5 82    mov    $0xffffffff82b53800,%rdi     /*** ffffffff82b53800 d console_owner_lock ***/
ffffffff8115d493:       48 89 eb                mov    %rbp,%rbx
ffffffff8115d496:       e8 5e b3 bf 00          callq  ffffffff81d587f9 <_raw_spin_lock>
ffffffff8115d49b:       44 8a 25 7e da 24 03    mov    0x324da7e(%rip),%r12b        # ffffffff843aaf20 <console_waiter>
        waiter = READ_ONCE(console_waiter);
        console_owner = NULL;
        raw_spin_unlock(&console_owner_lock);
ffffffff8115d4a2:       48 c7 c7 00 38 b5 82    mov    $0xffffffff82b53800,%rdi
{
        int waiter;

        raw_spin_lock(&console_owner_lock);
        waiter = READ_ONCE(console_waiter);
        console_owner = NULL;
ffffffff8115d4a9:       48 c7 05 ac da 24 03    movq   $0x0,0x324daac(%rip)        # ffffffff843aaf60 <console_owner>
ffffffff8115d4b0:       00 00 00 00
ffffffff8115d4b4:       81 e3 00 02 00 00       and    $0x200,%ebx
        raw_spin_unlock(&console_owner_lock);
ffffffff8115d4ba:       e8 95 b5 bf 00          callq  ffffffff81d58a54 <_raw_spin_unlock>

        if (!waiter) {
ffffffff8115d4bf:       45 84 e4                test   %r12b,%r12b
ffffffff8115d4c2:       0f 85 cf 04 00 00       jne    ffffffff8115d997 <console_unlock+0x5f6>
                spin_release(&console_owner_dep_map, 1, _THIS_IP_);
ffffffff8115d4c8:       e8 5a e5 06 00          callq  ffffffff811cba27 <__sanitizer_cov_trace_pc>
ffffffff8115d4cd:       48 c7 c2 c8 d4 15 81    mov    $0xffffffff8115d4c8,%rdx
ffffffff8115d4d4:       be 01 00 00 00          mov    $0x1,%esi
ffffffff8115d4d9:       48 c7 c7 80 38 b5 82    mov    $0xffffffff82b53880,%rdi
ffffffff8115d4e0:       e8 97 82 fe ff          callq  ffffffff8114577c <lock_release>
                if (console_lock_spinning_disable_and_check()) {
                        printk_safe_exit_irqrestore(flags);
                        return;
                }

                printk_safe_exit_irqrestore(flags);
ffffffff8115d4e5:       e8 f3 25 00 00          callq  ffffffff8115fadd <__printk_safe_exit>
ffffffff8115d4ea:       48 85 db                test   %rbx,%rbx
ffffffff8115d4ed:       0f 85 22 05 00 00       jne    ffffffff8115da15 <console_unlock+0x674>
ffffffff8115d4f3:       e8 2f e5 06 00          callq  ffffffff811cba27 <__sanitizer_cov_trace_pc>
ffffffff8115d4f8:       48 89 ef                mov    %rbp,%rdi
ffffffff8115d4fb:       e8 f4 cf ff ff          callq  ffffffff8115a4f4 <arch_local_irq_restore>
ffffffff8115d500:       e8 94 25 fe ff          callq  ffffffff8113fa99 <trace_hardirqs_off>

                if (do_cond_resched)
ffffffff8115d505:       e8 1d e5 06 00          callq  ffffffff811cba27 <__sanitizer_cov_trace_pc>
ffffffff8115d50a:       83 7c 24 18 00          cmpl   $0x0,0x18(%rsp)
ffffffff8115d50f:       74 1d                   je     ffffffff8115d52e <console_unlock+0x18d>
                        cond_resched();
ffffffff8115d511:       e8 11 e5 06 00          callq  ffffffff811cba27 <__sanitizer_cov_trace_pc>
ffffffff8115d516:       31 d2                   xor    %edx,%edx
ffffffff8115d518:       be 66 09 00 00          mov    $0x966,%esi
ffffffff8115d51d:       48 c7 c7 20 85 27 82    mov    $0xffffffff82278520,%rdi
ffffffff8115d524:       e8 24 8b fb ff          callq  ffffffff8111604d <___might_sleep>
ffffffff8115d529:       e8 ad 68 bf 00          callq  ffffffff81d53ddb <_cond_resched>

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ