WARNING in snd_pcm_hw_params

WARNING in snd_pcm_hw_params

[syzbot]

Hello,

syzbot hit the following crash on upstream commit
3c8ba0d61d04ced9f8d9ff93977995a9e4e96e91 (Sat Mar 31 01:52:36 2018 +0000)
kernel.h: Retain constant expression output for max()/min()
syzbot dashboard link:  
https://syzkaller.appspot.com/bug?extid=803e0047ac3a3096bb4f

So far this crash happened 6 times on upstream.
C reproducer: https://syzkaller.appspot.com/x/repro.c?id=5886672973594624
syzkaller reproducer:  
https://syzkaller.appspot.com/x/repro.syz?id=4913841943085056
Raw console output:  
https://syzkaller.appspot.com/x/log.txt?id=6314122077536256
Kernel config:  
https://syzkaller.appspot.com/x/.config?id=-1647968177339044852
compiler: gcc (GCC) 8.0.1 20180301 (experimental)

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+803e0047ac3a3096bb4f@syzkaller.appspotmail.com
It will help syzbot understand when the bug is fixed. See footer for  
details.
If you forward the report, please keep this part and the footer.

RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 0000000000441939
RDX: 0000000000000001 RSI: 0000000020000180 RDI: 0000000000000003
RBP: 00007ffe8c3569b0 R08: 0000000000000002 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000005
R13: ffffffffffffffff R14: 0000000000000000 R15: 0000000000000000
WARNING: CPU: 0 PID: 4468 at sound/core/pcm_native.c:620  
snd_pcm_hw_params_choose sound/core/pcm_native.c:620 [inline]
WARNING: CPU: 0 PID: 4468 at sound/core/pcm_native.c:620  
snd_pcm_hw_params+0x65a/0x1e20 sound/core/pcm_native.c:672
Kernel panic - not syncing: panic_on_warn set ...

CPU: 0 PID: 4468 Comm: syzkaller371267 Not tainted 4.16.0+ #2
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS  
Google 01/01/2011
Call Trace:
  __dump_stack lib/dump_stack.c:17 [inline]
  dump_stack+0x1b9/0x29f lib/dump_stack.c:53
  panic+0x22f/0x4de kernel/panic.c:183
  __warn.cold.8+0x163/0x1a3 kernel/panic.c:547
  report_bug+0x252/0x2d0 lib/bug.c:186
  fixup_bug arch/x86/kernel/traps.c:178 [inline]
  do_error_trap+0x1bc/0x470 arch/x86/kernel/traps.c:296
  do_invalid_op+0x1b/0x20 arch/x86/kernel/traps.c:315
  invalid_op+0x1b/0x40 arch/x86/entry/entry_64.S:991
RIP: 0010:snd_pcm_hw_params_choose sound/core/pcm_native.c:620 [inline]
RIP: 0010:snd_pcm_hw_params+0x65a/0x1e20 sound/core/pcm_native.c:672
RSP: 0018:ffff8801ac66f498 EFLAGS: 00010293
RAX: ffff8801acb86580 RBX: 00000000fffffff4 RCX: ffffffff859d7220
RDX: 0000000000000000 RSI: ffffffff859d752a RDI: 0000000000000005
RBP: ffff8801ac66f6e8 R08: ffff8801acb86580 R09: ffffed003b6046c2
R10: ffffed003b6046c2 R11: ffff8801db023613 R12: ffffffff8826309c
R13: ffff8801ceab6940 R14: ffff8801d9509200 R15: dffffc0000000000
  snd_pcm_kernel_ioctl+0x6c/0x240 sound/core/pcm_native.c:2999
  snd_pcm_oss_change_params_locked+0x1be8/0x3ce0 sound/core/oss/pcm_oss.c:993
  snd_pcm_oss_make_ready_locked+0xbc/0x130 sound/core/oss/pcm_oss.c:1182
  snd_pcm_oss_write1 sound/core/oss/pcm_oss.c:1396 [inline]
  snd_pcm_oss_write+0x516/0xa20 sound/core/oss/pcm_oss.c:2774
  __vfs_write+0x10b/0x880 fs/read_write.c:485
  vfs_write+0x1f8/0x560 fs/read_write.c:549
  ksys_write+0xf9/0x250 fs/read_write.c:598
  SYSC_write fs/read_write.c:610 [inline]
  SyS_write+0x24/0x30 fs/read_write.c:607
  do_syscall_64+0x29e/0x9d0 arch/x86/entry/common.c:287
  entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x441939
RSP: 002b:00007ffe8c3568e8 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 0000000000441939
RDX: 0000000000000001 RSI: 0000000020000180 RDI: 0000000000000003
RBP: 00007ffe8c3569b0 R08: 0000000000000002 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000005
R13: ffffffffffffffff R14: 0000000000000000 R15: 0000000000000000
Dumping ftrace buffer:
    (ftrace buffer empty)
Kernel Offset: disabled
Rebooting in 86400 seconds..


---
This bug is generated by a dumb bot. It may contain errors.
See https://goo.gl/tpsmEJ for details.
Direct all questions to syzkaller@googlegroups.com.

syzbot will keep track of this bug report.
If you forgot to add the Reported-by tag, once the fix for this bug is  
merged
into any tree, please reply to this email with:
#syz fix: exact-commit-title
If you want to test a patch for this bug, please reply with:
#syz test: git://repo/address.git branch
and provide the patch inline or as an attachment.
To mark this as a duplicate of another syzbot report, please reply with:
#syz dup: exact-subject-of-another-report
If it's a one-off invalid bug report, please reply with:
#syz invalid
Note: if the crash happens again, it will cause creation of a new bug  
report.
Note: all commands must start from beginning of the line in the email body.

Re: WARNING in snd_pcm_hw_params

[Takashi Iwai]

On Fri, 06 Apr 2018 02:02:02 +0200,
syzbot wrote:
> 
> WARNING: CPU: 0 PID: 4468 at sound/core/pcm_native.c:620
> snd_pcm_hw_params_choose sound/core/pcm_native.c:620 [inline]

This is a WARN_ON() to catch the inconsistent hw_params call.
This shouldn't happen in theory, but the reality looks weirder.

The necessary "fix" is just to get rid of snd_BUG_ON(), but still
wonder which condition it hits.  If it's an empty parameter, the
previous snd_pcm_hw_refine() should have caught and returned the error
beforehand...

In anyway this can't be a real crash, let's remove the warning to stop
the chorus of syzbot birds.


thanks,

Takashi

-- 8< --
From: Takashi Iwai <tiwai@suse.de>
Subject: [PATCH] ALSA: pcm: Remove WARN_ON() at snd_pcm_hw_params() error

snd_pcm_hw_params() may hit WARN_ON() when an inconsistent parameter
set is passed.  Although this should have been caught by the former
snd_pcm_hw_refine() and returned the error, syzkaller succeeded to
pass through and hit the WARN_ON(), which in turn made it panic
unnecessarily.

For reducing this kind of noise, let's drop snd_BUG_ON() check.

Reported-by: syzbot+803e0047ac3a3096bb4f@syzkaller.appspotmail.com
Signed-off-by: Takashi Iwai <tiwai@suse.de>
---
 sound/core/pcm_native.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/sound/core/pcm_native.c b/sound/core/pcm_native.c
index b84554893fab..35ffccea94c3 100644
--- a/sound/core/pcm_native.c
+++ b/sound/core/pcm_native.c
@@ -617,7 +617,7 @@ static int snd_pcm_hw_params_choose(struct snd_pcm_substream *pcm,
 			changed = snd_pcm_hw_param_first(pcm, params, *v, NULL);
 		else
 			changed = snd_pcm_hw_param_last(pcm, params, *v, NULL);
-		if (snd_BUG_ON(changed < 0))
+		if (changed < 0)
 			return changed;
 		if (changed == 0)
 			continue;
-- 
2.16.3

Re: WARNING in snd_pcm_hw_params

[Dmitry Vyukov]

On Mon, Apr 9, 2018 at 5:18 PM, Takashi Iwai <tiwai@suse.de> wrote:
> On Fri, 06 Apr 2018 02:02:02 +0200,
> syzbot wrote:
>>
>> WARNING: CPU: 0 PID: 4468 at sound/core/pcm_native.c:620
>> snd_pcm_hw_params_choose sound/core/pcm_native.c:620 [inline]
>
> This is a WARN_ON() to catch the inconsistent hw_params call.
> This shouldn't happen in theory, but the reality looks weirder.
>
> The necessary "fix" is just to get rid of snd_BUG_ON(), but still
> wonder which condition it hits.  If it's an empty parameter, the
> previous snd_pcm_hw_refine() should have caught and returned the error
> beforehand...

Hi Takashi,

The reproducer for this is trivially simple:

https://syzkaller.appspot.com/x/repro.syz?id=4913841943085056

(and I guess perf_event_open is red herring).

But the really important part there is probably this: Fault:true
FaultCall:2 FaultNth:18
And you can see where it actually happened in the raw console log:

Raw console output: https://syzkaller.appspot.com/x/log.txt?id=6314122077536256

Does it explain things?

> In anyway this can't be a real crash, let's remove the warning to stop
> the chorus of syzbot birds.
>
>
> thanks,
>
> Takashi
>
> -- 8< --
> From: Takashi Iwai <tiwai@suse.de>
> Subject: [PATCH] ALSA: pcm: Remove WARN_ON() at snd_pcm_hw_params() error
>
> snd_pcm_hw_params() may hit WARN_ON() when an inconsistent parameter
> set is passed.  Although this should have been caught by the former
> snd_pcm_hw_refine() and returned the error, syzkaller succeeded to
> pass through and hit the WARN_ON(), which in turn made it panic
> unnecessarily.
>
> For reducing this kind of noise, let's drop snd_BUG_ON() check.
>
> Reported-by: syzbot+803e0047ac3a3096bb4f@syzkaller.appspotmail.com
> Signed-off-by: Takashi Iwai <tiwai@suse.de>
> ---
>  sound/core/pcm_native.c | 2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
>
> diff --git a/sound/core/pcm_native.c b/sound/core/pcm_native.c
> index b84554893fab..35ffccea94c3 100644
> --- a/sound/core/pcm_native.c
> +++ b/sound/core/pcm_native.c
> @@ -617,7 +617,7 @@ static int snd_pcm_hw_params_choose(struct snd_pcm_substream *pcm,
>                         changed = snd_pcm_hw_param_first(pcm, params, *v, NULL);
>                 else
>                         changed = snd_pcm_hw_param_last(pcm, params, *v, NULL);
> -               if (snd_BUG_ON(changed < 0))
> +               if (changed < 0)
>                         return changed;
>                 if (changed == 0)
>                         continue;
> --
> 2.16.3
>
> --
> You received this message because you are subscribed to the Google Groups "syzkaller-bugs" group.
> To unsubscribe from this group and stop receiving emails from it, send an email to syzkaller-bugs+unsubscribe@googlegroups.com.
> To view this discussion on the web visit https://groups.google.com/d/msgid/syzkaller-bugs/s5hbmesflxu.wl-tiwai%40suse.de.
> For more options, visit https://groups.google.com/d/optout.

Re: WARNING in snd_pcm_hw_params

[Takashi Iwai]

On Mon, 09 Apr 2018 17:25:15 +0200,
Dmitry Vyukov wrote:
> 
> On Mon, Apr 9, 2018 at 5:18 PM, Takashi Iwai <tiwai@suse.de> wrote:
> > On Fri, 06 Apr 2018 02:02:02 +0200,
> > syzbot wrote:
> >>
> >> WARNING: CPU: 0 PID: 4468 at sound/core/pcm_native.c:620
> >> snd_pcm_hw_params_choose sound/core/pcm_native.c:620 [inline]
> >
> > This is a WARN_ON() to catch the inconsistent hw_params call.
> > This shouldn't happen in theory, but the reality looks weirder.
> >
> > The necessary "fix" is just to get rid of snd_BUG_ON(), but still
> > wonder which condition it hits.  If it's an empty parameter, the
> > previous snd_pcm_hw_refine() should have caught and returned the error
> > beforehand...
> 
> Hi Takashi,
> 
> The reproducer for this is trivially simple:
> 
> https://syzkaller.appspot.com/x/repro.syz?id=4913841943085056
> 
> (and I guess perf_event_open is red herring).
> 
> But the really important part there is probably this: Fault:true
> FaultCall:2 FaultNth:18
> And you can see where it actually happened in the raw console log:
> 
> Raw console output: https://syzkaller.appspot.com/x/log.txt?id=6314122077536256
> 
> Does it explain things?

Yes, it does.  So it's the kmalloc error from snd_pcm_hw_refine().
I overlooked this, as this kmalloc is relatively new, and that
possibility wasn't considered in the WARN_ON() in question.

I'll rephrase the changelog text.


Thanks!

Takashi

> 
> > In anyway this can't be a real crash, let's remove the warning to stop
> > the chorus of syzbot birds.
> >
> >
> > thanks,
> >
> > Takashi
> >
> > -- 8< --
> > From: Takashi Iwai <tiwai@suse.de>
> > Subject: [PATCH] ALSA: pcm: Remove WARN_ON() at snd_pcm_hw_params() error
> >
> > snd_pcm_hw_params() may hit WARN_ON() when an inconsistent parameter
> > set is passed.  Although this should have been caught by the former
> > snd_pcm_hw_refine() and returned the error, syzkaller succeeded to
> > pass through and hit the WARN_ON(), which in turn made it panic
> > unnecessarily.
> >
> > For reducing this kind of noise, let's drop snd_BUG_ON() check.
> >
> > Reported-by: syzbot+803e0047ac3a3096bb4f@syzkaller.appspotmail.com
> > Signed-off-by: Takashi Iwai <tiwai@suse.de>
> > ---
> >  sound/core/pcm_native.c | 2 +-
> >  1 file changed, 1 insertion(+), 1 deletion(-)
> >
> > diff --git a/sound/core/pcm_native.c b/sound/core/pcm_native.c
> > index b84554893fab..35ffccea94c3 100644
> > --- a/sound/core/pcm_native.c
> > +++ b/sound/core/pcm_native.c
> > @@ -617,7 +617,7 @@ static int snd_pcm_hw_params_choose(struct snd_pcm_substream *pcm,
> >                         changed = snd_pcm_hw_param_first(pcm, params, *v, NULL);
> >                 else
> >                         changed = snd_pcm_hw_param_last(pcm, params, *v, NULL);
> > -               if (snd_BUG_ON(changed < 0))
> > +               if (changed < 0)
> >                         return changed;
> >                 if (changed == 0)
> >                         continue;
> > --
> > 2.16.3
> >
> > --
> > You received this message because you are subscribed to the Google Groups "syzkaller-bugs" group.
> > To unsubscribe from this group and stop receiving emails from it, send an email to syzkaller-bugs+unsubscribe@googlegroups.com.
> > To view this discussion on the web visit https://groups.google.com/d/msgid/syzkaller-bugs/s5hbmesflxu.wl-tiwai%40suse.de.
> > For more options, visit https://groups.google.com/d/optout.
> 

Re: WARNING in snd_pcm_hw_params

[Takashi Iwai]

On Mon, 09 Apr 2018 17:33:45 +0200,
Takashi Iwai wrote:
> 
> On Mon, 09 Apr 2018 17:25:15 +0200,
> Dmitry Vyukov wrote:
> > 
> > On Mon, Apr 9, 2018 at 5:18 PM, Takashi Iwai <tiwai@suse.de> wrote:
> > > On Fri, 06 Apr 2018 02:02:02 +0200,
> > > syzbot wrote:
> > >>
> > >> WARNING: CPU: 0 PID: 4468 at sound/core/pcm_native.c:620
> > >> snd_pcm_hw_params_choose sound/core/pcm_native.c:620 [inline]
> > >
> > > This is a WARN_ON() to catch the inconsistent hw_params call.
> > > This shouldn't happen in theory, but the reality looks weirder.
> > >
> > > The necessary "fix" is just to get rid of snd_BUG_ON(), but still
> > > wonder which condition it hits.  If it's an empty parameter, the
> > > previous snd_pcm_hw_refine() should have caught and returned the error
> > > beforehand...
> > 
> > Hi Takashi,
> > 
> > The reproducer for this is trivially simple:
> > 
> > https://syzkaller.appspot.com/x/repro.syz?id=4913841943085056
> > 
> > (and I guess perf_event_open is red herring).
> > 
> > But the really important part there is probably this: Fault:true
> > FaultCall:2 FaultNth:18
> > And you can see where it actually happened in the raw console log:
> > 
> > Raw console output: https://syzkaller.appspot.com/x/log.txt?id=6314122077536256
> > 
> > Does it explain things?
> 
> Yes, it does.  So it's the kmalloc error from snd_pcm_hw_refine().
> I overlooked this, as this kmalloc is relatively new, and that
> possibility wasn't considered in the WARN_ON() in question.
> 
> I'll rephrase the changelog text.

... and below is the revised patch.  I'll queue for 4.17-rc1 merge.


Takashi

-- 8< --
From: Takashi Iwai <tiwai@suse.de>
Subject: [PATCH] ALSA: pcm: Remove WARN_ON() at snd_pcm_hw_params() error

snd_pcm_hw_params() (more exactly snd_pcm_hw_params_choose()) contains
a check of the return error from snd_pcm_hw_param_first() and _last()
with snd_BUG_ON() -- i.e. it may trigger WARN_ON() depending on the
kconfig.

This was a valid check in the past, as these functions shouldn't
return any error if the parameters have been already refined via
snd_pcm_hw_refine() beforehand.  However, the recent rewrite
introduced a kmalloc() in snd_pcm_hw_refine() for removing VLA, and
this brought a possibility to trigger an error.  As a result, syzbot
caught lots of superfluous kernel WARN_ON() and paniced via fault
injection.

As the WARN_ON() is no longer valid with the introduction of
kmalloc(), let's drop snd_BUG_ON() check, in order to make the world
peaceful place again.

Reported-by: syzbot+803e0047ac3a3096bb4f@syzkaller.appspotmail.com
Fixes: 5730f9f744cf ("ALSA: pcm: Remove VLA usage")
Signed-off-by: Takashi Iwai <tiwai@suse.de>
---
 sound/core/pcm_native.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/sound/core/pcm_native.c b/sound/core/pcm_native.c
index b84554893fab..35ffccea94c3 100644
--- a/sound/core/pcm_native.c
+++ b/sound/core/pcm_native.c
@@ -617,7 +617,7 @@ static int snd_pcm_hw_params_choose(struct snd_pcm_substream *pcm,
 			changed = snd_pcm_hw_param_first(pcm, params, *v, NULL);
 		else
 			changed = snd_pcm_hw_param_last(pcm, params, *v, NULL);
-		if (snd_BUG_ON(changed < 0))
+		if (changed < 0)
 			return changed;
 		if (changed == 0)
 			continue;
-- 
2.16.3