Messages in this thread | | | From | Dmitry Vyukov <> | Date | Mon, 18 Mar 2019 13:39:08 +0100 | Subject | Re: [syzbot? printk?] no WARN_ON() messages printed before "Kernel panic - not syncing: panic_on_warn set ..." |
| |
On Mon, Mar 18, 2019 at 1:32 PM Dmitry Vyukov <dvyukov@google.com> wrote: > > 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.
I've restricted fuzzer from invoking SYSLOG_ACTION_CONSOLE_LEVEL. Let's see if it helps.
| |