lkml.org 
[lkml]   [2019]   [Mar]   [16]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
From
Date
SubjectRe: [syzbot? printk?] no WARN_ON() messages printed before "Kernel panic - not syncing: panic_on_warn set ..."
On Sat, Mar 16, 2019 at 3:09 AM Tetsuo Handa
<penguin-kernel@i-love.sakura.ne.jp> wrote:
>
> Hello.
>
> I found a corrupted report at https://syzkaller.appspot.com/text?tag=CrashLog&x=17c6b82b200000 .
>
> The panic() was caused by by WARN_ON() from generic_make_request_checks(), but there
> was no printk() messages from WARN_ON(). Moreover, there was no printk() messages
> for (at least) nearly one minute despite syzbot's testing likely generates constant
> printk() messages. Unfortunately, since the report was truncated due to size limit,
> we can't check when was the last time prink() succeeded writing messages to consoles.
>
> ----------
> 14:27:02 executing program 1:
> (...snipped...)
> 14:28:00 executing program 3:
> (...snipped...)
> [ 974.068065][T22281] Kernel panic - not syncing: panic_on_warn set ...
> [ 974.085454][T22281] CPU: 1 PID: 22281 Comm: syz-executor.1 Not tainted 5.0.0+ #23
> [ 974.093121][T22281] Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
> [ 974.103193][T22281] Call Trace:
> [ 974.106513][T22281] dump_stack+0x172/0x1f0
> [ 974.110893][T22281] ? generic_make_request_checks+0x1be0/0x2160
> [ 974.117235][T22281] panic+0x2cb/0x65c
> [ 974.121434][T22281] ? __warn_printk+0xf3/0xf3
> [ 974.126064][T22281] ? generic_make_request_checks+0x1ca3/0x2160
> [ 974.132257][T22281] ? __sanitizer_cov_trace_const_cmp4+0x16/0x20
> [ 974.138521][T22281] ? __warn.cold+0x5/0x45
> [ 974.142877][T22281] ? __warn+0xe8/0x1d0
> [ 974.146978][T22281] ? generic_make_request_checks+0x1ca3/0x2160
> [ 974.153171][T22281] __warn.cold+0x20/0x45
> [ 974.157483][T22281] ? vprintk_emit+0x1ce/0x6d0
> [ 974.162202][T22281] ? generic_make_request_checks+0x1ca3/0x2160
> [ 974.168403][T22281] report_bug+0x263/0x2b0
> [ 974.172847][T22281] do_error_trap+0x11b/0x200
> [ 974.177646][T22281] do_invalid_op+0x37/0x50
> [ 974.182329][T22281] ? generic_make_request_checks+0x1ca3/0x2160
> [ 974.188951][T22281] invalid_op+0x14/0x20
> [ 974.193142][T22281] RIP: 0010:generic_make_request_checks+0x1ca3/0x2160
> ----------
>
> Is it possible that the reason there was no printk() messages is that
> someone kept printing messages to console from userspace such that
> console_trylock() from printk() was not able to succeed for (at least)
> nearly one minute?

Such reports showed up always with low frequency. For all that I
looked at we also always had a normal non-truncated version, so I was
never too worried.

If something would write from userspace, that would show up in the
output, or not?

Perhaps syzkaller somehow manages to lower console output level? I
figured out that we should restrict it from doing
syslog(SYSLOG_ACTION_CONSOLE_OFF). And I also restricted its access o
/dev/console. But maybe there is something else? It _should_ not be
able to write to random sysctl's.

\
 
 \ /
  Last update: 2019-03-16 10:12    [W:0.053 / U:32.296 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site