Re: [syzbot? printk?] no WARN_ON() messages printed before "Kernel panic - not syncing: panic_on_warn set ..."

[Dmitry Vyukov]

On Mon, Mar 18, 2019 at 6:27 AM Tetsuo Handa
<penguin-kernel@xxxxxxxxxxxxxxxxxxx> 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