linux-kernel - Re: [syzbot? printk?] no WARN_ON() messages printed before "Kernel panic

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: <127c9c3b-f878-174f-7065-66dc50fcabcf@i-love.sakura.ne.jp>
Date:   Wed, 8 May 2019 19:31:06 +0900
From:   Tetsuo Handa <penguin-kernel@...ove.sakura.ne.jp>
To:     Dmitry Vyukov <dvyukov@...gle.com>,
        Sergey Senozhatsky <sergey.senozhatsky@...il.com>
Cc:     Petr Mladek <pmladek@...e.com>,
        Sergey Senozhatsky <sergey.senozhatsky.work@...il.com>,
        LKML <linux-kernel@...r.kernel.org>,
        syzkaller <syzkaller@...glegroups.com>
Subject: Re: [syzbot? printk?] no WARN_ON() messages printed before "Kernel
 panic - not syncing: panic_on_warn set ..."

Hello.

We are again getting corrupted reports where message from WARN() is missing.
For example, https://syzkaller.appspot.com/text?tag=CrashLog&x=1720cac8a00000 was
titled as "WARNING in cgroup_exit" because the
"WARNING: CPU: 0 PID: 7870 at kernel/cgroup/cgroup.c:6008 cgroup_exit+0x51a/0x5d0"
line is there but https://syzkaller.appspot.com/text?tag=CrashLog&x=1670a602a00000
was titled as "corrupted report (2)" because the
"WARNING: CPU: 0 PID: 10223 at kernel/cgroup/cgroup.c:6008 cgroup_exit+0x51a/0x5d0"
line is missing. Also, it is unlikely that there was no printk() for a few minutes.
Thus, I suspect something is again suppressing console output.
Since this problem is happening in 5.1.0-next-20190507, do we want to try below one?

 kernel/printk/printk.c | 20 ++++++++++++++++++++
 1 file changed, 20 insertions(+)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index e1e8250..f0b9463 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -3338,3 +3338,23 @@ void kmsg_dump_rewind(struct kmsg_dumper *dumper)
 EXPORT_SYMBOL_GPL(kmsg_dump_rewind);

 #endif
+
+#ifdef CONFIG_DEBUG_AID_FOR_SYZBOT
+static int initial_loglevel;
+static void check_loglevel(struct timer_list *timer)
+{
+	if (console_loglevel < initial_loglevel)
+		panic("Console loglevel changed (%d->%d)!", initial_loglevel,
+		      console_loglevel);
+	mod_timer(timer, jiffies + HZ);
+}
+static int __init loglevelcheck_init(void)
+{
+	static DEFINE_TIMER(timer, check_loglevel);
+
+	initial_loglevel = console_loglevel;
+	mod_timer(&timer, jiffies + HZ);
+	return 0;
+}
+late_initcall(loglevelcheck_init);
+#endif

By the way, recently we are hitting false positives caused by "WARNING:"
string from not WARN() messages but plain printk() messages (e.g.

  https://syzkaller.appspot.com/bug?id=31bdef63e48688854fde93e6edf390922b70f8a4
  https://syzkaller.appspot.com/bug?id=faae4720a75cadb8cd0dbda5c4d3542228d37340

) and we need to avoid emitting "WARNING:" string from plain printk() messages
during fuzzing testing. I guess we want to add something like
CONFIG_DEBUG_AID_FOR_SYZBOT to all kernels in order to mask such string...