INFO: rcu detected stall in snd_pcm_oss_write3 (2)

[syzbot]

Hello,

syzbot hit the following crash on upstream commit
e02d37bf55a9a36f22427fd6dd733fe104d817b6 (Thu Apr 5 17:42:07 2018 +0000)
Merge tag 'sound-4.17-rc1' of
git://git.kernel.org/pub/scm/linux/kernel/git/tiwai/sound
syzbot dashboard link:
https://syzkaller.appspot.com/bug?extid=150189c103427d31a053

So far this crash happened 3 times on upstream.
Unfortunately, I don't have any reproducer for this crash yet.
Raw console output:
https://syzkaller.appspot.com/x/log.txt?id=6067392849379328
Kernel config:
https://syzkaller.appspot.com/x/.config?id=-4805825610197092128
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+150189...@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.

Buffer I/O error on dev loop0, logical block 6, lost async page write
Buffer I/O error on dev loop0, logical block 7, lost async page write
Buffer I/O error on dev loop0, logical block 8, lost async page write
Buffer I/O error on dev loop0, logical block 9, lost async page write
Buffer I/O error on dev loop0, logical block 10, lost async page write
INFO: rcu_sched self-detected stall on CPU
1-....: (124998 ticks this GP) idle=9b2/1/4611686018427387906
softirq=22733/22733 fqs=31170
(t=125000 jiffies g=11599 c=11598 q=1619)
NMI backtrace for cpu 1
CPU: 1 PID: 7184 Comm: syz-executor3 Not tainted 4.16.0+ #2
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Call Trace:
<IRQ>
__dump_stack lib/dump_stack.c:17 [inline]
dump_stack+0x1b9/0x29f lib/dump_stack.c:53
nmi_cpu_backtrace.cold.4+0x19/0xce lib/nmi_backtrace.c:103
nmi_trigger_cpumask_backtrace+0x151/0x192 lib/nmi_backtrace.c:62
arch_trigger_cpumask_backtrace+0x14/0x20 arch/x86/kernel/apic/hw_nmi.c:38
trigger_single_cpu_backtrace include/linux/nmi.h:156 [inline]
rcu_dump_cpu_stacks+0x175/0x1c2 kernel/rcu/tree.c:1376
print_cpu_stall kernel/rcu/tree.c:1525 [inline]
check_cpu_stall.isra.61.cold.80+0x36c/0x59a kernel/rcu/tree.c:1593
__rcu_pending kernel/rcu/tree.c:3356 [inline]
rcu_pending kernel/rcu/tree.c:3401 [inline]
rcu_check_callbacks+0x21b/0xad0 kernel/rcu/tree.c:2763
update_process_times+0x2d/0x70 kernel/time/timer.c:1636
tick_sched_handle+0xa0/0x180 kernel/time/tick-sched.c:171
tick_sched_timer+0x42/0x130 kernel/time/tick-sched.c:1179
__run_hrtimer kernel/time/hrtimer.c:1337 [inline]
__hrtimer_run_queues+0x3e3/0x10a0 kernel/time/hrtimer.c:1399
hrtimer_interrupt+0x286/0x650 kernel/time/hrtimer.c:1457
local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1025 [inline]
smp_apic_timer_interrupt+0x15d/0x710 arch/x86/kernel/apic/apic.c:1050
apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:862
</IRQ>
RIP: 0010:__sanitizer_cov_trace_pc+0x2b/0x50 kernel/kcov.c:101
RSP: 0018:ffff8801cfe77710 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff13
RAX: ffff8801d0108080 RBX: 0000000000000004 RCX: ffffffff85a1f955
RDX: 0000000000000002 RSI: ffffffff85a1f95f RDI: 0000000000000005
RBP: ffff8801cfe77710 R08: ffff8801d0108080 R09: 0000000000000006
R10: ffff8801d0108080 R11: 0000000000000000 R12: 0000000000000001
R13: ffff8801ceb2cd80 R14: ffff8801aaacec00 R15: ffffffffffffffe0
snd_pcm_oss_write3+0x16f/0x220 sound/core/oss/pcm_oss.c:1224
io_playback_transfer+0x274/0x310 sound/core/oss/io.c:47
snd_pcm_plug_write_transfer+0x36c/0x470 sound/core/oss/pcm_plugin.c:619
snd_pcm_oss_write2+0x25c/0x460 sound/core/oss/pcm_oss.c:1365
snd_pcm_oss_sync1+0x332/0x5a0 sound/core/oss/pcm_oss.c:1606
snd_pcm_oss_sync.isra.29+0x790/0x980 sound/core/oss/pcm_oss.c:1682
snd_pcm_oss_release+0x214/0x290 sound/core/oss/pcm_oss.c:2559
__fput+0x34d/0x890 fs/file_table.c:209
____fput+0x15/0x20 fs/file_table.c:243
task_work_run+0x1e4/0x290 kernel/task_work.c:113
tracehook_notify_resume include/linux/tracehook.h:191 [inline]
exit_to_usermode_loop+0x2bd/0x310 arch/x86/entry/common.c:166
prepare_exit_to_usermode arch/x86/entry/common.c:196 [inline]
syscall_return_slowpath arch/x86/entry/common.c:265 [inline]
do_syscall_64+0x792/0x9d0 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x4552d9
RSP: 002b:00007f4e5ffe6c68 EFLAGS: 00000246 ORIG_RAX: 0000000000000003
RAX: 0000000000000000 RBX: 00007f4e5ffe76d4 RCX: 00000000004552d9
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000013
RBP: 000000000072bea0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
R13: 0000000000000052 R14: 00000000006f3850 R15: 0000000000000000
INFO: rcu_sched detected expedited stalls on CPUs/tasks: { 1-... } 127452
jiffies s: 2685 root: 0x2/.
blocking rcu_node structures:
Task dump for CPU 1:
syz-executor3 R running task 24120 7184 4559 0x0000000c
Call Trace:


---
This bug is generated by a dumb bot. It may contain errors.
See https://goo.gl/tpsmEJ for details.
Direct all questions to syzk...@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
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.

[syzbot]

syzbot has found reproducer for the following crash on upstream commit
38c23685b273cfb4ccf31a199feccce3bdcb5d83 (Fri Apr 6 04:29:35 2018 +0000)
Merge tag 'armsoc-drivers' of
git://git.kernel.org/pub/scm/linux/kernel/git/arm/arm-soc

syzbot dashboard link:
https://syzkaller.appspot.com/bug?extid=150189c103427d31a053

So far this crash happened 15 times on upstream.
C reproducer: https://syzkaller.appspot.com/x/repro.c?id=5405588854931456
syzkaller reproducer:
https://syzkaller.appspot.com/x/repro.syz?id=5561439796330496
Raw console output:
https://syzkaller.appspot.com/x/log.txt?id=5697900571000832
Kernel config:
https://syzkaller.appspot.com/x/.config?id=-5813481738265533882

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+150189...@syzkaller.appspotmail.com
It will help syzbot understand when the bug is fixed.

IPVS: ftp: loaded support on port[0] = 21

INFO: rcu_sched self-detected stall on CPU

1-....: (124999 ticks this GP) idle=622/1/4611686018427387906
softirq=10596/10596 fqs=31239
(t=125000 jiffies g=4952 c=4951 q=20)

NMI backtrace for cpu 1

CPU: 1 PID: 4474 Comm: syzkaller631460 Not tainted 4.16.0+ #3

Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Call Trace:
<IRQ>

__dump_stack lib/dump_stack.c:77 [inline]
dump_stack+0x1b9/0x294 lib/dump_stack.c:113

nmi_cpu_backtrace.cold.4+0x19/0xce lib/nmi_backtrace.c:103
nmi_trigger_cpumask_backtrace+0x151/0x192 lib/nmi_backtrace.c:62
arch_trigger_cpumask_backtrace+0x14/0x20 arch/x86/kernel/apic/hw_nmi.c:38
trigger_single_cpu_backtrace include/linux/nmi.h:156 [inline]
rcu_dump_cpu_stacks+0x175/0x1c2 kernel/rcu/tree.c:1376
print_cpu_stall kernel/rcu/tree.c:1525 [inline]
check_cpu_stall.isra.61.cold.80+0x36c/0x59a kernel/rcu/tree.c:1593
__rcu_pending kernel/rcu/tree.c:3356 [inline]
rcu_pending kernel/rcu/tree.c:3401 [inline]
rcu_check_callbacks+0x21b/0xad0 kernel/rcu/tree.c:2763
update_process_times+0x2d/0x70 kernel/time/timer.c:1636
tick_sched_handle+0xa0/0x180 kernel/time/tick-sched.c:171
tick_sched_timer+0x42/0x130 kernel/time/tick-sched.c:1179
__run_hrtimer kernel/time/hrtimer.c:1337 [inline]
__hrtimer_run_queues+0x3e3/0x10a0 kernel/time/hrtimer.c:1399
hrtimer_interrupt+0x286/0x650 kernel/time/hrtimer.c:1457
local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1025 [inline]
smp_apic_timer_interrupt+0x15d/0x710 arch/x86/kernel/apic/apic.c:1050
apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:862
</IRQ>

RIP: 0010:__snd_pcm_lib_xfer+0x768/0x1d10 sound/core/pcm_lib.c:2111
RSP: 0018:ffff8801b7b76ea8 EFLAGS: 00000286 ORIG_RAX: ffffffffffffff13
RAX: 0000000000000000 RBX: ffffffffffffffe0 RCX: ffffed0036f6edec
RDX: 0000000000000000 RSI: ffffffff859ff04e RDI: ffffed0036f6edf0
RBP: ffff8801b7b77148 R08: ffff8801afeae9b8 R09: 0000000000000006
R10: ffff8801afeae140 R11: 0000000000000000 R12: 0000000000000004
R13: 00000000ffffffe0 R14: ffff8801af2165c0 R15: ffff8801ceaec000
snd_pcm_oss_write3+0xe9/0x220 sound/core/oss/pcm_oss.c:1236

io_playback_transfer+0x274/0x310 sound/core/oss/io.c:47
snd_pcm_plug_write_transfer+0x36c/0x470 sound/core/oss/pcm_plugin.c:619
snd_pcm_oss_write2+0x25c/0x460 sound/core/oss/pcm_oss.c:1365
snd_pcm_oss_sync1+0x332/0x5a0 sound/core/oss/pcm_oss.c:1606
snd_pcm_oss_sync.isra.29+0x790/0x980 sound/core/oss/pcm_oss.c:1682
snd_pcm_oss_release+0x214/0x290 sound/core/oss/pcm_oss.c:2559
__fput+0x34d/0x890 fs/file_table.c:209
____fput+0x15/0x20 fs/file_table.c:243
task_work_run+0x1e4/0x290 kernel/task_work.c:113

exit_task_work include/linux/task_work.h:22 [inline]
do_exit+0x1aee/0x2730 kernel/exit.c:865
do_group_exit+0x16f/0x430 kernel/exit.c:968
SYSC_exit_group kernel/exit.c:979 [inline]
SyS_exit_group+0x1d/0x20 kernel/exit.c:977
do_syscall_64+0x29e/0x9d0 arch/x86/entry/common.c:287
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x4446e9
RSP: 002b:00007ffe29466408 EFLAGS: 00000202 ORIG_RAX: 00000000000000e7
RAX: ffffffffffffffda RBX: ffffffffffffffff RCX: 00000000004446e9
RDX: 00000000004446e9 RSI: 0000000000000080 RDI: 0000000000000001
RBP: 00000000006cf018 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000202 R12: 0000000000401ff0
R13: 0000000000402080 R14: 0000000000000000 R15: 0000000000000000

[Takashi Iwai]

On Fri, 06 Apr 2018 23:14:01 +0200,
syzbot wrote:
>
> syzbot has found reproducer for the following crash on upstream commit
> 38c23685b273cfb4ccf31a199feccce3bdcb5d83 (Fri Apr 6 04:29:35 2018 +0000)
> Merge tag 'armsoc-drivers' of
> git://git.kernel.org/pub/scm/linux/kernel/git/arm/arm-soc
> syzbot dashboard link:
> https://syzkaller.appspot.com/bug?extid=150189c103427d31a053
>
> So far this crash happened 15 times on upstream.
> C reproducer: https://syzkaller.appspot.com/x/repro.c?id=5405588854931456
> syzkaller reproducer:
> https://syzkaller.appspot.com/x/repro.syz?id=5561439796330496
> Raw console output:
> https://syzkaller.appspot.com/x/log.txt?id=5697900571000832
> Kernel config:
> https://syzkaller.appspot.com/x/.config?id=-5813481738265533882
> compiler: gcc (GCC) 8.0.1 20180301 (experimental)

Thanks to the reproducer, I could spot out now.
Below is the patch (which was submitted as well).


thanks,

Takashi

-- 8< --
From: Takashi Iwai <ti...@suse.de>
Subject: [PATCH] ALSA: pcm: Fix endless loop for XRUN recovery in OSS
emulation

The commit 02a5d6925cd3 ("ALSA: pcm: Avoid potential races between OSS
ioctls and read/write") split the PCM preparation code to a locked
version, and it added a sanity check of runtime->oss.prepare flag
along with the change. This leaded to an endless loop when the stream
gets XRUN: namely, snd_pcm_oss_write3() and co call
snd_pcm_oss_prepare() without setting runtime->oss.prepare flag and
the loop continues until the PCM state reaches to another one.

As the function is supposed to execute the preparation
unconditionally, drop the invalid state check there.

The bug was triggered by syzkaller.

Fixes: 02a5d6925cd3 ("ALSA: pcm: Avoid potential races between OSS ioctls and read/write")
Reported-by: syzbot+7e3f31...@syzkaller.appspotmail.com
Reported-by: syzbot+4f2016...@syzkaller.appspotmail.com
Cc: <sta...@vger.kernel.org>
Signed-off-by: Takashi Iwai <ti...@suse.de>
---
sound/core/oss/pcm_oss.c | 3 +--
1 file changed, 1 insertion(+), 2 deletions(-)

diff --git a/sound/core/oss/pcm_oss.c b/sound/core/oss/pcm_oss.c
index 481ab0e94ffa..727647755aab 100644
--- a/sound/core/oss/pcm_oss.c
+++ b/sound/core/oss/pcm_oss.c
@@ -1128,13 +1128,12 @@ static int snd_pcm_oss_get_active_substream(struct snd_pcm_oss_file *pcm_oss_fil
}

/* call with params_lock held */
+/* NOTE: this doesn't care whether runtime->oss.prepare is set or not */
static int snd_pcm_oss_prepare(struct snd_pcm_substream *substream)
{
int err;
struct snd_pcm_runtime *runtime = substream->runtime;

- if (!runtime->oss.prepare)
- return 0;
err = snd_pcm_kernel_ioctl(substream, SNDRV_PCM_IOCTL_PREPARE, NULL);
if (err < 0) {
pcm_dbg(substream->pcm,
--
2.16.3

[Dmitry Vyukov]

On Sat, Apr 7, 2018 at 11:56 AM, Takashi Iwai <ti...@suse.de> wrote:
> On Fri, 06 Apr 2018 23:14:01 +0200,
> syzbot wrote:
>>
>> syzbot has found reproducer for the following crash on upstream commit
>> 38c23685b273cfb4ccf31a199feccce3bdcb5d83 (Fri Apr 6 04:29:35 2018 +0000)
>> Merge tag 'armsoc-drivers' of
>> git://git.kernel.org/pub/scm/linux/kernel/git/arm/arm-soc
>> syzbot dashboard link:
>> https://syzkaller.appspot.com/bug?extid=150189c103427d31a053
>>
>> So far this crash happened 15 times on upstream.
>> C reproducer: https://syzkaller.appspot.com/x/repro.c?id=5405588854931456
>> syzkaller reproducer:
>> https://syzkaller.appspot.com/x/repro.syz?id=5561439796330496
>> Raw console output:
>> https://syzkaller.appspot.com/x/log.txt?id=5697900571000832
>> Kernel config:
>> https://syzkaller.appspot.com/x/.config?id=-5813481738265533882
>> compiler: gcc (GCC) 8.0.1 20180301 (experimental)
>
> Thanks to the reproducer, I could spot out now.
> Below is the patch (which was submitted as well).

Great!

There are 3 more recent stalls in sound, does this fix them as well?

https://groups.google.com/forum/#!msg/syzkaller-bugs/MGfk8WH3O6k/ja2xKpdcCAAJ
https://groups.google.com/forum/#!msg/syzkaller-bugs/74HglwU94go/T89ohzlYCAAJ
https://groups.google.com/forum/#!msg/syzkaller-bugs/D2xWV7WTRDk/5y2kZyBICAAJ

[Takashi Iwai]

Yes, very likely.


Takashi

[Dmitry Vyukov]

#syz dup: INFO: rcu detected stall in io_playback_transfer