lkml.org 
[lkml]   [2019]   [Mar]   [18]   [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 Mon, Mar 18, 2019 at 1:07 PM Dmitry Vyukov <dvyukov@google.com> wrote:
>
> On Mon, Mar 18, 2019 at 6:27 AM Tetsuo Handa
> <penguin-kernel@i-love.sakura.ne.jp> wrote:
> >
> > Dmitry Vyukov wrote:
> > > > Then, we need to find what test is changing console_loglevel.
> > > > Maybe add debug BUG_ON() in linux-next.git using CONFIG_DEBUG_AID_FOR_SYZBOT ?
> > >
> > > Is there a single place to catch this? I could run syzkaller locally
> > > first with the check.
> > >
> >
> > There is no such place. But not so many places change permanently.
> > For x86, you can test with below patch applied.
> >
> > ---
> > drivers/tty/sysrq.c | 1 +
> > kernel/printk/printk.c | 3 +++
> > kernel/sysctl.c | 23 ++++++++++++++++++++++-
> > 3 files changed, 26 insertions(+), 1 deletion(-)
> >
> > diff --git a/drivers/tty/sysrq.c b/drivers/tty/sysrq.c
> > index fa0ce7d..ad73520 100644
> > --- a/drivers/tty/sysrq.c
> > +++ b/drivers/tty/sysrq.c
> > @@ -91,6 +91,7 @@ static void sysrq_handle_loglevel(int key)
> > i = key - '0';
> > console_loglevel = CONSOLE_LOGLEVEL_DEFAULT;
> > pr_info("Loglevel set to %d\n", i);
> > + WARN_ONCE(i < CONSOLE_LOGLEVEL_DEFAULT, "Reducing console_loglevel to %d", i);
> > console_loglevel = i;
> > }
> > static struct sysrq_key_op sysrq_loglevel_op = {
> > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> > index 02ca827..70d1f8c 100644
> > --- a/kernel/printk/printk.c
> > +++ b/kernel/printk/printk.c
> > @@ -1533,11 +1533,13 @@ int do_syslog(int type, char __user *buf, int len, int source)
> > case SYSLOG_ACTION_CONSOLE_OFF:
> > if (saved_console_loglevel == LOGLEVEL_DEFAULT)
> > saved_console_loglevel = console_loglevel;
> > + WARN_ONCE(minimum_console_loglevel < CONSOLE_LOGLEVEL_DEFAULT, "Reducing console_loglevel to %d", minimum_console_loglevel);
> > console_loglevel = minimum_console_loglevel;
> > break;
> > /* Enable logging to console */
> > case SYSLOG_ACTION_CONSOLE_ON:
> > if (saved_console_loglevel != LOGLEVEL_DEFAULT) {
> > + WARN_ONCE(saved_console_loglevel < CONSOLE_LOGLEVEL_DEFAULT, "Reducing console_loglevel to %d", saved_console_loglevel);
> > console_loglevel = saved_console_loglevel;
> > saved_console_loglevel = LOGLEVEL_DEFAULT;
> > }
> > @@ -1548,6 +1550,7 @@ int do_syslog(int type, char __user *buf, int len, int source)
> > return -EINVAL;
> > if (len < minimum_console_loglevel)
> > len = minimum_console_loglevel;
> > + WARN_ONCE(len < CONSOLE_LOGLEVEL_DEFAULT, "Reducing console_loglevel to %d", len);
> > console_loglevel = len;
> > /* Implicitly re-enable logging to console */
> > saved_console_loglevel = LOGLEVEL_DEFAULT;
> > diff --git a/kernel/sysctl.c b/kernel/sysctl.c
> > index b3df3ab..2170421 100644
> > --- a/kernel/sysctl.c
> > +++ b/kernel/sysctl.c
> > @@ -273,6 +273,27 @@ static int sysrq_sysctl_handler(struct ctl_table *table, int write,
> > int sysctl_legacy_va_layout;
> > #endif
> >
> > +static int proc_dointvec_loglevel(struct ctl_table *table, int write,
> > + void __user *buffer, size_t *lenp, loff_t *ppos)
> > +{
> > + if (write && buffer && *lenp) {
> > + size_t len = *lenp;
> > + char *kbuf, *p;
> > +
> > + if (len > PAGE_SIZE - 1)
> > + len = PAGE_SIZE - 1;
> > + p = kbuf = memdup_user_nul(buffer, len);
> > + if (IS_ERR(kbuf))
> > + return PTR_ERR(kbuf);
> > + while (*p && (*p < '0' || *p > '9'))
> > + p++;
> > + len = *p ? strtoul(p, &p, 10) : CONSOLE_LOGLEVEL_DEFAULT;
> > + WARN_ONCE(len < CONSOLE_LOGLEVEL_DEFAULT, "Reducing console_loglevel to %d", (int) len);
> > + kfree(kbuf);
> > + }
> > + return proc_dointvec(table, write, buffer, lenp, ppos);
> > +}
> > +
> > /* The default sysctl tables: */
> >
> > static struct ctl_table sysctl_base_table[] = {
> > @@ -839,7 +860,7 @@ static int sysrq_sysctl_handler(struct ctl_table *table, int write,
> > .data = &console_loglevel,
> > .maxlen = 4*sizeof(int),
> > .mode = 0644,
> > - .proc_handler = proc_dointvec,
> > + .proc_handler = proc_dointvec_loglevel,
> > },
> > {
> > .procname = "printk_ratelimit",
> > --
> > 1.8.3.1
>
>
> Thanks.
> Running this for 10 mins I only got a bunch of these, so at least none
> of these WARNs does not trigger immediately. But I will continue
> running it.
>
> WARNING in schedule_bh
> kernel BUG at ./include/linux/mm.h:LINE!
> WARNING in vkms_vblank_simulate
> general protection fault in xfrmi_decode_session
> INFO: task hung in corrupted
> kernel BUG at drivers/android/binder_alloc.c:LINE!
> BUG: unable to handle kernel NULL pointer dereference in
> drm_atomic_helper_commit_modeset_disables
> INFO: task hung in __rq_qos_throttle
> WARNING in sk_stream_kill_queues


Wait, but isn't SYSLOG_ACTION_CONSOLE_LEVEL what we are looking for?
syzkaller knows about the syslog syscall:
https://github.com/google/syzkaller/blob/13026d10f09f0e801c342e6c009ff580d49b894b/sys/linux/sys.txt#L322
and even though it does not know SYSLOG_ACTION_CONSOLE_LEVEL const, it
can guess that number.

\
 
 \ /
  Last update: 2019-03-18 13:32    [W:0.106 / U:0.584 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site