linux-kernel - Re: [lkp-robot] [printk] c162d5b433: BUG:KASAN:use-after-scope_in

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: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <20180228155941.34z45rjz3bjqde7w@pathway.suse.cz>
Date:   Wed, 28 Feb 2018 16:59:41 +0100
From:   Petr Mladek <pmladek@...e.com>
To:     kernel test robot <shun.hao@...el.com>
Cc:     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>,
        Tetsuo Handa <penguin-kernel@...ove.SAKURA.ne.jp>,
        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
Subject: Re: [lkp-robot] [printk]  c162d5b433: BUG:KASAN:use-after-scope_in_c

On Wed 2018-02-28 11:23:34, Petr Mladek wrote:
> On Sat 2018-02-24 13:34:05, kernel test robot wrote:
> > TO: Petr Mladek <pmladek@...e.com>
> > CC: 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>, Tetsuo Handa <penguin-kernel@...ove.SAKURA.ne.jp>, Byungchul Park <byungchul.park@....com>, Tejun Heo <tj@...nel.org>, Pavel Machek <pavel@....cz>, Steven Rostedt (VMware) <rostedt@...dmis.org>, Sergey Senozhatsky <sergey.senozhatsky@...il.com>, LKML <linux-kernel@...r.kernel.org>, linux-kernel@...r.kernel.org, lkp@...org
> > 
> > 
> > 
> > FYI, we noticed the following commit (built with gcc-7):
> > 
> > commit: c162d5b4338d72deed61aa65ed0f2f4ba2bbc8ab ("printk: Hide console waiter logic into helpers")
> > https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
> > 
> > in testcase: boot
> > 
> > on test machine: qemu-system-x86_64 -enable-kvm -cpu host -smp 2 -m 1G
> > 
> > caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
> > 
> > 
> > +--------------------------------+------------+------------+
> > |                                | dbdda842fe | c162d5b433 |
> > +--------------------------------+------------+------------+
> > | boot_successes                 | 0          | 0          |
> > | boot_failures                  | 18         | 16         |
> > | BUG:KASAN:use-after-scope_in_p | 18         |            |
> > | BUG:KASAN:use-after-scope_in_c | 0          | 16         |
> > +--------------------------------+------------+------------+
> > 
> > 
> > 
> > [    0.003333] BUG: KASAN: use-after-scope in console_unlock+0x185/0x960
> > [    0.003333] BUG: KASAN: use-after-scope in console_unlock+0x185/0x960
> 
> Is there any change to get disassembly of console_unlock() from the
> problematic build?
> 
> I have troubles to reproduce this myself. Also I was not able to find any
> bug just by looking into the code yet. The disassembly might help
> a lot here.
> 
> 
> Interesting symptoms (for myself and other debuggers):
> 
> The lines are duplicated. Therefore it happened when real
> console was registered and before the early console was unregistered.
> See also the full dmesg for these actions. The related printk messages
> are right after the KASAN report.
> 
> I wonder if it is unsafe to pass the console_lock via
> console_trylock_spinnning() from console_unlock() called
> in register_console(). I do not see any problem but I might
> be blind.

The KASAN report is between the following lines in dmesg:

[    0.003333]  Offload RCU callbacks from CPUs: .
[    0.003333] ==================================================================
[    0.003333] ==================================================================
[    0.003333] BUG: KASAN: use-after-scope in console_unlock+0x185/0x960
[    0.003333] BUG: KASAN: use-after-scope in console_unlock+0x185/0x960
[...]
[    0.003333] console [ttyS0] enabled

The first message is printed from rcu_init_nohz().
The last message is printed from register_console().

I would expect that the KASAN message is triggered from the following
code:

	rcu_init_nohz();
	init_timers();
	hrtimers_init();
	softirq_init();
	timekeeping_init();
	time_init();
	sched_clock_postinit();
	printk_safe_init();
	perf_event_init();
	profile_init();
	call_function_init();
	WARN(!irqs_disabled(), "Interrupts were enabled early\n");
	early_boot_irqs_disabled = false;
	local_irq_enable();

	kmem_cache_init_late();

	/*
	 * HACK ALERT! This is early. We're enabling the console before
	 * we've done PCI setups etc, and console_init() must be aware of
	 * this. But we do want output early, in case something goes wrong.
	 */
	console_init();


I am just confused that I do not see any of this function on the
stack. Note that this code is still called in the single CPU mode.

I feel lost a bit.

I am really curious what code is proceed on the line
console_unlock+0x185/0x960.

Best Regards,
Petr