LKML Archive on lore.kernel.org
help / color / mirror / Atom feed
* INFO: rcu detected stall in ext4_file_write_iter
@ 2021-10-06  8:20 Hao Sun
  0 siblings, 0 replies; 9+ messages in thread
From: Hao Sun @ 2021-10-06  8:20 UTC (permalink / raw)
  To: Linux Kernel Mailing List
  Cc: bp, hpa, jmattson, joro, kvm, mingo, pbonzini, seanjc, tglx,
	vkuznets, wanpengli, x86, linux-ext4, tytso, adilger.kernel

Hello,

When using Healer to fuzz the latest Linux kernel, the following crash
was triggered.

HEAD commit: 0513e464f900 Merge tag 'perf-tools-fixes-for-v5.15-2021-09-27'
git tree: upstream
console output:
https://drive.google.com/file/d/1EUGmGiPEMh6IuR3fukiHWFlCBR8flhyB/view?usp=sharing
kernel config: https://drive.google.com/file/d/1Jqhc4DpCVE8X7d-XBdQnrMoQzifTG5ho/view?usp=sharing

Sorry, I don't have a reproducer for this crash, hope the symbolized
report can help.
If you fix this issue, please add the following tag to the commit:
Reported-by: Hao Sun <sunhao.th@gmail.com>

rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
rcu: 0-...0: (2 ticks this GP) idle=437/1/0x4000000000000000
softirq=7937/7937 fqs=2360
rcu: 2-...0: (123 ticks this GP) idle=e27/1/0x4000000000000000
softirq=8738/8738 fqs=2360
(detected by 1, t=10530 jiffies, g=9469, q=85)
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 9701 Comm: syz-executor Not tainted 5.15.0-rc3+ #21
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
rel-1.12.0-59-gc9ba5276e321-prebuilt.qemu.org 04/01/2014
RIP: 0010:kvm_wait+0x4a/0x70 arch/x86/kernel/kvm.c:893
Code: 5d c3 89 f3 48 89 fd 9c 58 fa f6 c4 02 75 30 0f b6 45 00 38 c3
74 16 e8 f4 81 25 00 fb 5b 5d c3 eb 07 0f 00 2d 15 c4 6d 03 f4 <5b> 5d
c3 e8 de 81 25 00 eb 07 0f 00 2d 03 c4 6d 03 fb f4 eb c0 e8
RSP: 0018:ffffc90000003e00 EFLAGS: 00000046
RAX: 0000000000000003 RBX: ffff8881019e0338 RCX: 0000000000000008
RDX: 0000000000000000 RSI: 0000000000000003 RDI: ffff8881019e0338
RBP: ffff88807dc2a600 R08: 0000000000000000 R09: 0000000000000001
R10: ffffc90000003d20 R11: 0000000000000005 R12: 0000000000000001
R13: 0000000000000100 R14: 0000000000000000 R15: 0000000000040000
FS:  00007fdb8fc96700(0000) GS:ffff88807dc00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007fe208c8f010 CR3: 000000010b7ef000 CR4: 0000000000750ef0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
PKRU: 55555554
Call Trace:
 <IRQ>
 pv_wait arch/x86/include/asm/paravirt.h:597 [inline]
 pv_wait_head_or_lock kernel/locking/qspinlock_paravirt.h:470 [inline]
 __pv_queued_spin_lock_slowpath+0x262/0x330 kernel/locking/qspinlock.c:508
 pv_queued_spin_lock_slowpath arch/x86/include/asm/paravirt.h:585 [inline]
 queued_spin_lock_slowpath arch/x86/include/asm/qspinlock.h:51 [inline]
 queued_spin_lock include/asm-generic/qspinlock.h:85 [inline]
 do_raw_spin_lock+0xb6/0xc0 kernel/locking/spinlock_debug.c:115
 spin_lock include/linux/spinlock.h:363 [inline]
 drm_handle_vblank+0x86/0x530 drivers/gpu/drm/drm_vblank.c:1951
 vkms_vblank_simulate+0x5a/0x190 drivers/gpu/drm/vkms/vkms_crtc.c:29
 __run_hrtimer kernel/time/hrtimer.c:1685 [inline]
 __hrtimer_run_queues+0xb8/0x610 kernel/time/hrtimer.c:1749
 hrtimer_interrupt+0xfe/0x280 kernel/time/hrtimer.c:1811
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1086 [inline]
 __sysvec_apic_timer_interrupt+0x9c/0x2c0 arch/x86/kernel/apic/apic.c:1103
 sysvec_apic_timer_interrupt+0x99/0xc0 arch/x86/kernel/apic/apic.c:1097
 </IRQ>
 asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:638
RIP: 0010:clear_page_erms+0x7/0x10 arch/x86/lib/clear_page_64.S:49
Code: 48 89 47 18 48 89 47 20 48 89 47 28 48 89 47 30 48 89 47 38 48
8d 7f 40 75 d9 90 c3 0f 1f 80 00 00 00 00 b9 00 10 00 00 31 c0 <f3> aa
c3 cc cc cc cc cc cc 41 57 41 56 41 55 41 54 55 53 48 89 fb
RSP: 0018:ffffc9000358f4c8 EFLAGS: 00010246
RAX: 0000000000000000 RBX: 0000000000241e80 RCX: 0000000000001000
RDX: ffff88800ed3a280 RSI: 0000000000000001 RDI: ffff88800907a000
RBP: 0000000000241ec0 R08: 0000000000001000 R09: 0000000000000001
R10: ffffc9000358f4a8 R11: 0000000000000003 R12: ffff888000000000
R13: 0000000000012c50 R14: 0000000000000000 R15: ffff88807fffb700
 clear_page arch/x86/include/asm/page_64.h:49 [inline]
 clear_highpage include/linux/highmem.h:181 [inline]
 kernel_init_free_pages.part.95+0x67/0xa0 mm/page_alloc.c:1278
 kernel_init_free_pages mm/page_alloc.c:1267 [inline]
 post_alloc_hook+0x70/0x110 mm/page_alloc.c:2414
 prep_new_page+0x16/0x50 mm/page_alloc.c:2424
 get_page_from_freelist+0x64d/0x29a0 mm/page_alloc.c:4153
 __alloc_pages+0xde/0x2a0 mm/page_alloc.c:5375
 alloc_pages+0x85/0x150 mm/mempolicy.c:2197
 alloc_slab_page mm/slub.c:1763 [inline]
 allocate_slab mm/slub.c:1900 [inline]
 new_slab+0x2ce/0x4f0 mm/slub.c:1963
 ___slab_alloc+0x90e/0xec0 mm/slub.c:2994
 __slab_alloc.isra.91+0x4f/0xb0 mm/slub.c:3081
 slab_alloc_node mm/slub.c:3172 [inline]
 slab_alloc mm/slub.c:3214 [inline]
 kmem_cache_alloc+0x25f/0x280 mm/slub.c:3219
 kmem_cache_zalloc include/linux/slab.h:711 [inline]
 alloc_buffer_head+0x1c/0xa0 fs/buffer.c:3309
 alloc_page_buffers+0x155/0x390 fs/buffer.c:832
 create_empty_buffers+0x24/0x310 fs/buffer.c:1560
 ext4_block_write_begin+0x6ec/0x980 fs/ext4/inode.c:1060
 ext4_da_write_begin+0x275/0x610 fs/ext4/inode.c:3021
 generic_perform_write+0xce/0x220 mm/filemap.c:3770
 ext4_buffered_write_iter+0xd6/0x190 fs/ext4/file.c:269
 ext4_file_write_iter+0x80/0x940 fs/ext4/file.c:680
 call_write_iter include/linux/fs.h:2163 [inline]
 do_iter_readv_writev+0x1e8/0x2b0 fs/read_write.c:729
 do_iter_write+0xaf/0x250 fs/read_write.c:855
 vfs_iter_write+0x38/0x60 fs/read_write.c:896
 iter_file_splice_write+0x2d8/0x450 fs/splice.c:689
 do_splice_from fs/splice.c:767 [inline]
 direct_splice_actor+0x4a/0x80 fs/splice.c:936
 splice_direct_to_actor+0x123/0x2d0 fs/splice.c:891
 do_splice_direct+0xc3/0x110 fs/splice.c:979
 do_sendfile+0x338/0x740 fs/read_write.c:1249
 __do_sys_sendfile64 fs/read_write.c:1314 [inline]
 __se_sys_sendfile64 fs/read_write.c:1300 [inline]
 __x64_sys_sendfile64+0xc7/0xe0 fs/read_write.c:1300
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x34/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x46ae99
Code: f7 d8 64 89 02 b8 ff ff ff ff c3 66 0f 1f 44 00 00 48 89 f8 48
89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d
01 f0 ff ff 73 01 c3 48 c7 c1 bc ff ff ff f7 d8 64 89 01 48
RSP: 002b:00007fdb8fc95c48 EFLAGS: 00000246 ORIG_RAX: 0000000000000028
RAX: ffffffffffffffda RBX: 000000000078c0a0 RCX: 000000000046ae99
RDX: 0000000000000000 RSI: 0000000000000008 RDI: 0000000000000003
RBP: 00000000004e4809 R08: 0000000000000000 R09: 0000000000000000
R10: 00008400fffffffb R11: 0000000000000246 R12: 000000000078c0a0
R13: 0000000000000000 R14: 000000000078c0a0 R15: 00007fffa528c490
Sending NMI from CPU 1 to CPUs 2:
NMI backtrace for cpu 2
CPU: 2 PID: 27 Comm: ksoftirqd/2 Not tainted 5.15.0-rc3+ #21
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS
rel-1.12.0-59-gc9ba5276e321-prebuilt.qemu.org 04/01/2014
RIP: 0010:__lock_acquire+0x7de/0x1d60 kernel/locking/lockdep.c:5010
Code: f0 09 00 00 0f 8d 0e 03 00 00 49 63 c4 48 89 ee 48 8d 04 80 49
8d 3c c6 e8 1f 37 f9 02 85 c0 74 d8 4c 8b 34 24 44 8b 64 24 44 <44> 8b
05 d3 36 e2 04 45 85 c0 75 51 8b 7c 24 08 85 ff 0f 85 18 05
RSP: 0018:ffffc90000727b28 EFLAGS: 00010046
RAX: 0000000000000000 RBX: ffff888009900a70 RCX: 000000000b087fe1
RDX: 0000000000000008 RSI: 0000000000000000 RDI: ffff888009900000
RBP: 0000000000000057 R08: ffffffff8816e4e0 R09: 0000000000000001
R10: ffffc90000727b28 R11: 0000000000000003 R12: 0000000000000000
R13: ffff888009900000 R14: ffff8880099009f8 R15: 10b087fec69640ce
FS:  0000000000000000(0000) GS:ffff88807dd00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000000736090 CR3: 000000000588a000 CR4: 0000000000750ee0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
PKRU: 55555554
Call Trace:
 lock_acquire+0x1f9/0x340 kernel/locking/lockdep.c:5625
 __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
 _raw_spin_lock_irqsave+0x38/0x50 kernel/locking/spinlock.c:162
 lock_hrtimer_base+0x2f/0x70 kernel/time/hrtimer.c:173
 hrtimer_try_to_cancel+0x6d/0x270 kernel/time/hrtimer.c:1331
 hrtimer_cancel+0x12/0x30 kernel/time/hrtimer.c:1443
 __disable_vblank drivers/gpu/drm/drm_vblank.c:434 [inline]
 drm_vblank_disable_and_save+0xca/0x130 drivers/gpu/drm/drm_vblank.c:478
 vblank_disable_fn+0x83/0xa0 drivers/gpu/drm/drm_vblank.c:495
 call_timer_fn+0xcb/0x3f0 kernel/time/timer.c:1421
 expire_timers kernel/time/timer.c:1466 [inline]
 __run_timers kernel/time/timer.c:1734 [inline]
 run_timer_softirq+0x6bd/0x820 kernel/time/timer.c:1747
 __do_softirq+0xe9/0x561 kernel/softirq.c:558
 run_ksoftirqd+0x2d/0x60 kernel/softirq.c:920
 smpboot_thread_fn+0x225/0x320 kernel/smpboot.c:164
 kthread+0x178/0x1b0 kernel/kthread.c:319
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
----------------
Code disassembly (best guess):
   0: 5d                    pop    %rbp
   1: c3                    retq
   2: 89 f3                mov    %esi,%ebx
   4: 48 89 fd              mov    %rdi,%rbp
   7: 9c                    pushfq
   8: 58                    pop    %rax
   9: fa                    cli
   a: f6 c4 02              test   $0x2,%ah
   d: 75 30                jne    0x3f
   f: 0f b6 45 00          movzbl 0x0(%rbp),%eax
  13: 38 c3                cmp    %al,%bl
  15: 74 16                je     0x2d
  17: e8 f4 81 25 00        callq  0x258210
  1c: fb                    sti
  1d: 5b                    pop    %rbx
  1e: 5d                    pop    %rbp
  1f: c3                    retq
  20: eb 07                jmp    0x29
  22: 0f 00 2d 15 c4 6d 03 verw   0x36dc415(%rip)        # 0x36dc43e
  29: f4                    hlt
* 2a: 5b                    pop    %rbx <-- trapping instruction
  2b: 5d                    pop    %rbp
  2c: c3                    retq
  2d: e8 de 81 25 00        callq  0x258210
  32: eb 07                jmp    0x3b
  34: 0f 00 2d 03 c4 6d 03 verw   0x36dc403(%rip)        # 0x36dc43e
  3b: fb                    sti
  3c: f4                    hlt
  3d: eb c0                jmp    0xffffffff
  3f: e8                    .byte 0xe8

^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: INFO: rcu detected stall in ext4_file_write_iter
  2020-09-11 19:33 ` syzbot
@ 2020-09-11 20:03   ` Jens Axboe
  0 siblings, 0 replies; 9+ messages in thread
From: Jens Axboe @ 2020-09-11 20:03 UTC (permalink / raw)
  To: syzbot, acme, adilger.kernel, dvyukov, fweisbec, linux-ext4,
	linux-fsdevel, linux-kernel, ming.lei, mingo, mingo,
	penguin-kernel, peterz, syzkaller-bugs, tglx, tytso

#syz fix: block: allow for_each_bvec to support zero len bvec


-- 
Jens Axboe


^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: INFO: rcu detected stall in ext4_file_write_iter
  2019-02-26  6:50 syzbot
  2019-02-26 15:17 ` Theodore Y. Ts'o
  2019-03-21 17:30 ` syzbot
@ 2020-09-11 19:33 ` syzbot
  2020-09-11 20:03   ` Jens Axboe
  2 siblings, 1 reply; 9+ messages in thread
From: syzbot @ 2020-09-11 19:33 UTC (permalink / raw)
  To: acme, adilger.kernel, axboe, dvyukov, fweisbec, linux-ext4,
	linux-fsdevel, linux-kernel, ming.lei, mingo, mingo,
	penguin-kernel, peterz, syzkaller-bugs, tglx, tytso

syzbot suspects this issue was fixed by commit:

commit 7e24969022cbd61ddc586f14824fc205661bb124
Author: Ming Lei <ming.lei@redhat.com>
Date:   Mon Aug 17 10:00:55 2020 +0000

    block: allow for_each_bvec to support zero len bvec

bisection log:  https://syzkaller.appspot.com/x/bisect.txt?x=1120f201900000
start commit:   92ed3019 Linux 5.8-rc7
git tree:       upstream
kernel config:  https://syzkaller.appspot.com/x/.config?x=84f076779e989e69
dashboard link: https://syzkaller.appspot.com/bug?extid=7d19c5fe6a3f1161abb7
syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=170f7cbc900000
C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=16a25e38900000

If the result looks correct, please mark the issue as fixed by replying with:

#syz fix: block: allow for_each_bvec to support zero len bvec

For information about bisection process see: https://goo.gl/tpsmEJ#bisection

^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: INFO: rcu detected stall in ext4_file_write_iter
  2019-02-26  6:50 syzbot
  2019-02-26 15:17 ` Theodore Y. Ts'o
@ 2019-03-21 17:30 ` syzbot
  2020-09-11 19:33 ` syzbot
  2 siblings, 0 replies; 9+ messages in thread
From: syzbot @ 2019-03-21 17:30 UTC (permalink / raw)
  To: acme, adilger.kernel, dvyukov, linux-ext4, linux-fsdevel,
	linux-kernel, mingo, peterz, syzkaller-bugs, tytso

Bisection is inconclusive: the bug happens on the oldest tested release.

bisection log:  https://syzkaller.appspot.com/x/bisect.txt?x=17b1becf200000
start commit:   [unknown
git tree:       upstream
final crash:    https://syzkaller.appspot.com/x/report.txt?x=1471becf200000
console output: https://syzkaller.appspot.com/x/log.txt?x=1071becf200000
dashboard link: https://syzkaller.appspot.com/bug?extid=7d19c5fe6a3f1161abb7
syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=103908f8c00000
C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=105e5cd0c00000

For information about bisection process see: https://goo.gl/tpsmEJ#bisection

^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: INFO: rcu detected stall in ext4_file_write_iter
  2019-02-27 21:57     ` Theodore Y. Ts'o
@ 2019-02-28  9:34       ` Dmitry Vyukov
  0 siblings, 0 replies; 9+ messages in thread
From: Dmitry Vyukov @ 2019-02-28  9:34 UTC (permalink / raw)
  To: Theodore Y. Ts'o, Dmitry Vyukov, syzbot, Andreas Dilger,
	linux-ext4, LKML, linux-fsdevel, syzkaller-bugs, Peter Zijlstra,
	Ingo Molnar, Arnaldo Carvalho de Melo

On Wed, Feb 27, 2019 at 10:58 PM Theodore Y. Ts'o <tytso@mit.edu> wrote:
>
> On Wed, Feb 27, 2019 at 10:58:50AM +0100, Dmitry Vyukov wrote:
> > Peter, Ingo, do you have any updates on the
> > perf_event_open/sched_setattr stalls? This bug cause assorted hangs
> > throughout kernel and so is nasty.
> >
> > syzkaller tries to remove all syscalls from reproducers one-by-one.
> > Somehow without sched_setattr the hang did not reproduce (a bunch of
> > repros have perf_event_open+sched_setattr so somehow they seem to be
> > related)
>
> FWIW, at least for me, the repro.c with sched_setattr commented out
> (see the repro.c attached to a message[1] earlier in the thread) it
> was reproducing reliably on a 2 CPU, 2 GB memory KVM using the
> ext4.git tree (dev branch, 5.0-rc3 plus ext4 commits for the next
> merge window) using a Debian stable-based VM[2].
>
> [1] https://groups.google.com/d/msg/syzkaller-bugs/ByPpM3WZw1s/li7SsaEyAgAJ
> [2] https://mirrors.edge.kernel.org/pub/linux/kernel/people/tytso/kvm-xfstests/root_fs.img.amd64
>
> > But even with perfect repros machines still won't be
> > able to tell in all cases that even though the hang happened in ext4
> > code, the root cause is actually another scheduler-related system
> > call. So thanks for looking into this.
>
> To be clear, there was *not* a scheduler-related system call in the
> repro.c I was playing with (see [2]); just perf_event_open(2) and
> sendfile(2).

Let me correct the statement then:

But even with perfect repros machines still won't be able to tell in
all cases that even though the hang happened in ext4 code, the root
cause is actually another perf-related system call. So thanks for
looking into this.

^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: INFO: rcu detected stall in ext4_file_write_iter
  2019-02-27  9:58   ` Dmitry Vyukov
@ 2019-02-27 21:57     ` Theodore Y. Ts'o
  2019-02-28  9:34       ` Dmitry Vyukov
  0 siblings, 1 reply; 9+ messages in thread
From: Theodore Y. Ts'o @ 2019-02-27 21:57 UTC (permalink / raw)
  To: Dmitry Vyukov
  Cc: syzbot, Andreas Dilger, linux-ext4, LKML, linux-fsdevel,
	syzkaller-bugs, Peter Zijlstra, Ingo Molnar,
	Arnaldo Carvalho de Melo

On Wed, Feb 27, 2019 at 10:58:50AM +0100, Dmitry Vyukov wrote:
> Peter, Ingo, do you have any updates on the
> perf_event_open/sched_setattr stalls? This bug cause assorted hangs
> throughout kernel and so is nasty.
> 
> syzkaller tries to remove all syscalls from reproducers one-by-one.
> Somehow without sched_setattr the hang did not reproduce (a bunch of
> repros have perf_event_open+sched_setattr so somehow they seem to be
> related)

FWIW, at least for me, the repro.c with sched_setattr commented out
(see the repro.c attached to a message[1] earlier in the thread) it
was reproducing reliably on a 2 CPU, 2 GB memory KVM using the
ext4.git tree (dev branch, 5.0-rc3 plus ext4 commits for the next
merge window) using a Debian stable-based VM[2].

[1] https://groups.google.com/d/msg/syzkaller-bugs/ByPpM3WZw1s/li7SsaEyAgAJ
[2] https://mirrors.edge.kernel.org/pub/linux/kernel/people/tytso/kvm-xfstests/root_fs.img.amd64

> But even with perfect repros machines still won't be
> able to tell in all cases that even though the hang happened in ext4
> code, the root cause is actually another scheduler-related system
> call. So thanks for looking into this.

To be clear, there was *not* a scheduler-related system call in the
repro.c I was playing with (see [2]); just perf_event_open(2) and
sendfile(2).

Cheers,

	      	      	    	 		    	- Ted

^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: INFO: rcu detected stall in ext4_file_write_iter
  2019-02-26 15:17 ` Theodore Y. Ts'o
@ 2019-02-27  9:58   ` Dmitry Vyukov
  2019-02-27 21:57     ` Theodore Y. Ts'o
  0 siblings, 1 reply; 9+ messages in thread
From: Dmitry Vyukov @ 2019-02-27  9:58 UTC (permalink / raw)
  To: Theodore Y. Ts'o, syzbot, Andreas Dilger, linux-ext4, LKML,
	linux-fsdevel, syzkaller-bugs, Peter Zijlstra, Ingo Molnar,
	Arnaldo Carvalho de Melo

On Tue, Feb 26, 2019 at 4:17 PM Theodore Y. Ts'o <tytso@mit.edu> wrote:
>
> TL;DR: This doesn't appear to be ext4 specific, and seems to involve
> an unholy combination of the perf_event_open(2) and sendfile(2) system
> calls.
>
> On Mon, Feb 25, 2019 at 10:50:05PM -0800, syzbot wrote:
> > syzbot found the following crash on:
> >
> > HEAD commit:    8a61716ff2ab Merge tag 'ceph-for-5.0-rc8' of git://github...
> > git tree:       upstream
> > console output: https://syzkaller.appspot.com/x/log.txt?x=161b71d4c00000
> > kernel config:  https://syzkaller.appspot.com/x/.config?x=7132344728e7ec3f
> > dashboard link: https://syzkaller.appspot.com/bug?extid=7d19c5fe6a3f1161abb7
> > compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
> > syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=103908f8c00000
> > C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=105e5cd0c00000
> >
> > IMPORTANT: if you fix the bug, please add the following tag to the commit:
> > Reported-by: syzbot+7d19c5fe6a3f1161abb7@syzkaller.appspotmail.com
> >
> > audit: type=1400 audit(1550814986.750:36): avc:  denied  { map } for
> > pid=8058 comm="syz-executor004" path="/root/syz-executor004991115"
> > dev="sda1" ino=1426 scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023
> > tcontext=unconfined_u:object_r:user_home_t:s0 tclass=file permissive=1
> > hrtimer: interrupt took 42841 ns
> > rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
> > rcu:  (detected by 1, t=10502 jiffies, g=5873, q=2)
> > rcu: All QSes seen, last rcu_preempt kthread activity 10502
> > (4295059997-4295049495), jiffies_till_next_fqs=1, root ->qsmask 0x0
> > syz-executor004 R  running task    26448  8069   8060 0x00000000
>
> This particular repro seems to induce similar failures when I tried it
> with xfs and btrfs as well as ext4.
>
> The repro seems to involve the perf_event_open(2) and sendfile(2)
> system calls, and killing the process which is performing the
> sendfile(2).  The repro also uses the sched_setattr(2) system call,
> but when I commented it out, the failure still happened, so this
> appears to be another case of "Syzkaller?  We don't need to bug
> developers with a minimal test case!  Open source developers are a
> free unlimited resource, after all!"  :-)
>
> Commenting out the perf_event_open(2) does seem to make the problem go
> away.
>
> Since there are zillions of ways to self-DOS a Linux server without
> having to resert to exotic combination of system calls, this isn't
> something I'm going to prioritize for myself, but I'm hoping someone
> else has time and curiosity.

Peter, Ingo, do you have any updates on the
perf_event_open/sched_setattr stalls? This bug cause assorted hangs
throughout kernel and so is nasty.

syzkaller tries to remove all syscalls from reproducers one-by-one.
Somehow without sched_setattr the hang did not reproduce (a bunch of
repros have perf_event_open+sched_setattr so somehow they seem to be
related). Kernel is not as simple as a single-threaded deterministic
fully-reproducible user-space xml parsing library, more (almost all)
aspects are flaky and non-deterministic and thus require more human
intelligence. But even with perfect repros machines still won't be
able to tell in all cases that even though the hang happened in ext4
code, the root cause is actually another scheduler-related system
call. So thanks for looking into this.

^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: INFO: rcu detected stall in ext4_file_write_iter
  2019-02-26  6:50 syzbot
@ 2019-02-26 15:17 ` Theodore Y. Ts'o
  2019-02-27  9:58   ` Dmitry Vyukov
  2019-03-21 17:30 ` syzbot
  2020-09-11 19:33 ` syzbot
  2 siblings, 1 reply; 9+ messages in thread
From: Theodore Y. Ts'o @ 2019-02-26 15:17 UTC (permalink / raw)
  To: syzbot
  Cc: adilger.kernel, linux-ext4, linux-kernel, linux-fsdevel,
	syzkaller-bugs, Peter Zijlstra, Ingo Molnar,
	Arnaldo Carvalho de Melo

[-- Attachment #1: Type: text/plain, Size: 2446 bytes --]

TL;DR: This doesn't appear to be ext4 specific, and seems to involve
an unholy combination of the perf_event_open(2) and sendfile(2) system
calls.

On Mon, Feb 25, 2019 at 10:50:05PM -0800, syzbot wrote:
> syzbot found the following crash on:
> 
> HEAD commit:    8a61716ff2ab Merge tag 'ceph-for-5.0-rc8' of git://github...
> git tree:       upstream
> console output: https://syzkaller.appspot.com/x/log.txt?x=161b71d4c00000
> kernel config:  https://syzkaller.appspot.com/x/.config?x=7132344728e7ec3f
> dashboard link: https://syzkaller.appspot.com/bug?extid=7d19c5fe6a3f1161abb7
> compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
> syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=103908f8c00000
> C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=105e5cd0c00000
> 
> IMPORTANT: if you fix the bug, please add the following tag to the commit:
> Reported-by: syzbot+7d19c5fe6a3f1161abb7@syzkaller.appspotmail.com
> 
> audit: type=1400 audit(1550814986.750:36): avc:  denied  { map } for
> pid=8058 comm="syz-executor004" path="/root/syz-executor004991115"
> dev="sda1" ino=1426 scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023
> tcontext=unconfined_u:object_r:user_home_t:s0 tclass=file permissive=1
> hrtimer: interrupt took 42841 ns
> rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
> rcu: 	(detected by 1, t=10502 jiffies, g=5873, q=2)
> rcu: All QSes seen, last rcu_preempt kthread activity 10502
> (4295059997-4295049495), jiffies_till_next_fqs=1, root ->qsmask 0x0
> syz-executor004 R  running task    26448  8069   8060 0x00000000

This particular repro seems to induce similar failures when I tried it
with xfs and btrfs as well as ext4.

The repro seems to involve the perf_event_open(2) and sendfile(2)
system calls, and killing the process which is performing the
sendfile(2).  The repro also uses the sched_setattr(2) system call,
but when I commented it out, the failure still happened, so this
appears to be another case of "Syzkaller?  We don't need to bug
developers with a minimal test case!  Open source developers are a
free unlimited resource, after all!"  :-)

Commenting out the perf_event_open(2) does seem to make the problem go
away.

Since there are zillions of ways to self-DOS a Linux server without
having to resert to exotic combination of system calls, this isn't
something I'm going to prioritize for myself, but I'm hoping someone
else has time and curiosity.

					- Ted

[-- Attachment #2: repro.c --]
[-- Type: text/x-csrc, Size: 11507 bytes --]

// autogenerated by syzkaller (https://github.com/google/syzkaller)

#define _GNU_SOURCE

#include <dirent.h>
#include <endian.h>
#include <errno.h>
#include <fcntl.h>
#include <pthread.h>
#include <signal.h>
#include <stdint.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <sys/ioctl.h>
#include <sys/mount.h>
#include <sys/prctl.h>
#include <sys/stat.h>
#include <sys/syscall.h>
#include <sys/types.h>
#include <sys/wait.h>
#include <time.h>
#include <unistd.h>

#include <linux/futex.h>

unsigned long long procid;

static void sleep_ms(uint64_t ms)
{
  usleep(ms * 1000);
}

static uint64_t current_time_ms(void)
{
  struct timespec ts;
  if (clock_gettime(CLOCK_MONOTONIC, &ts))
    exit(1);
  return (uint64_t)ts.tv_sec * 1000 + (uint64_t)ts.tv_nsec / 1000000;
}

static void use_temporary_dir(void)
{
  char tmpdir_template[] = "./syzkaller.XXXXXX";
  char* tmpdir = mkdtemp(tmpdir_template);
  if (!tmpdir)
    exit(1);
  if (chmod(tmpdir, 0777))
    exit(1);
  if (chdir(tmpdir))
    exit(1);
}

static void thread_start(void* (*fn)(void*), void* arg)
{
  pthread_t th;
  pthread_attr_t attr;
  pthread_attr_init(&attr);
  pthread_attr_setstacksize(&attr, 128 << 10);
  int i;
  for (i = 0; i < 100; i++) {
    if (pthread_create(&th, &attr, fn, arg) == 0) {
      pthread_attr_destroy(&attr);
      return;
    }
    if (errno == EAGAIN) {
      usleep(50);
      continue;
    }
    break;
  }
  exit(1);
}

#define BITMASK(bf_off, bf_len) (((1ull << (bf_len)) - 1) << (bf_off))
#define STORE_BY_BITMASK(type, htobe, addr, val, bf_off, bf_len)               \
  *(type*)(addr) =                                                             \
      htobe((htobe(*(type*)(addr)) & ~BITMASK((bf_off), (bf_len))) |           \
            (((type)(val) << (bf_off)) & BITMASK((bf_off), (bf_len))))

typedef struct {
  int state;
} event_t;

static void event_init(event_t* ev)
{
  ev->state = 0;
}

static void event_reset(event_t* ev)
{
  ev->state = 0;
}

static void event_set(event_t* ev)
{
  if (ev->state)
    exit(1);
  __atomic_store_n(&ev->state, 1, __ATOMIC_RELEASE);
  syscall(SYS_futex, &ev->state, FUTEX_WAKE | FUTEX_PRIVATE_FLAG);
}

static void event_wait(event_t* ev)
{
  while (!__atomic_load_n(&ev->state, __ATOMIC_ACQUIRE))
    syscall(SYS_futex, &ev->state, FUTEX_WAIT | FUTEX_PRIVATE_FLAG, 0, 0);
}

static int event_isset(event_t* ev)
{
  return __atomic_load_n(&ev->state, __ATOMIC_ACQUIRE);
}

static int event_timedwait(event_t* ev, uint64_t timeout)
{
  uint64_t start = current_time_ms();
  uint64_t now = start;
  for (;;) {
    uint64_t remain = timeout - (now - start);
    struct timespec ts;
    ts.tv_sec = remain / 1000;
    ts.tv_nsec = (remain % 1000) * 1000 * 1000;
    syscall(SYS_futex, &ev->state, FUTEX_WAIT | FUTEX_PRIVATE_FLAG, 0, &ts);
    if (__atomic_load_n(&ev->state, __ATOMIC_RELAXED))
      return 1;
    now = current_time_ms();
    if (now - start > timeout)
      return 0;
  }
}

#define FS_IOC_SETFLAGS _IOW('f', 2, long)
static void remove_dir(const char* dir)
{
  DIR* dp;
  struct dirent* ep;
  int iter = 0;
retry:
  while (umount2(dir, MNT_DETACH) == 0) {
  }
  dp = opendir(dir);
  if (dp == NULL) {
    if (errno == EMFILE) {
      exit(1);
    }
    exit(1);
  }
  while ((ep = readdir(dp))) {
    if (strcmp(ep->d_name, ".") == 0 || strcmp(ep->d_name, "..") == 0)
      continue;
    char filename[FILENAME_MAX];
    snprintf(filename, sizeof(filename), "%s/%s", dir, ep->d_name);
    while (umount2(filename, MNT_DETACH) == 0) {
    }
    struct stat st;
    if (lstat(filename, &st))
      exit(1);
    if (S_ISDIR(st.st_mode)) {
      remove_dir(filename);
      continue;
    }
    int i;
    for (i = 0;; i++) {
      if (unlink(filename) == 0)
        break;
      if (errno == EPERM) {
        int fd = open(filename, O_RDONLY);
        if (fd != -1) {
          long flags = 0;
          if (ioctl(fd, FS_IOC_SETFLAGS, &flags) == 0)
            close(fd);
          continue;
        }
      }
      if (errno == EROFS) {
        break;
      }
      if (errno != EBUSY || i > 100)
        exit(1);
      if (umount2(filename, MNT_DETACH))
        exit(1);
    }
  }
  closedir(dp);
  int i;
  for (i = 0;; i++) {
    if (rmdir(dir) == 0)
      break;
    if (i < 100) {
      if (errno == EPERM) {
        int fd = open(dir, O_RDONLY);
        if (fd != -1) {
          long flags = 0;
          if (ioctl(fd, FS_IOC_SETFLAGS, &flags) == 0)
            close(fd);
          continue;
        }
      }
      if (errno == EROFS) {
        break;
      }
      if (errno == EBUSY) {
        if (umount2(dir, MNT_DETACH))
          exit(1);
        continue;
      }
      if (errno == ENOTEMPTY) {
        if (iter < 100) {
          iter++;
          goto retry;
        }
      }
    }
    exit(1);
  }
}

static void kill_and_wait(int pid, int* status)
{
  kill(-pid, SIGKILL);
  kill(pid, SIGKILL);
  int i;
  for (i = 0; i < 100; i++) {
    if (waitpid(-1, status, WNOHANG | __WALL) == pid)
      return;
    usleep(1000);
  }
  DIR* dir = opendir("/sys/fs/fuse/connections");
  if (dir) {
    for (;;) {
      struct dirent* ent = readdir(dir);
      if (!ent)
        break;
      if (strcmp(ent->d_name, ".") == 0 || strcmp(ent->d_name, "..") == 0)
        continue;
      char abort[300];
      snprintf(abort, sizeof(abort), "/sys/fs/fuse/connections/%s/abort",
               ent->d_name);
      int fd = open(abort, O_WRONLY);
      if (fd == -1) {
        continue;
      }
      if (write(fd, abort, 1) < 0) {
      }
      close(fd);
    }
    closedir(dir);
  } else {
  }
  while (waitpid(-1, status, __WALL) != pid) {
  }
}

#define SYZ_HAVE_SETUP_TEST 1
static void setup_test()
{
  prctl(PR_SET_PDEATHSIG, SIGKILL, 0, 0, 0);
  setpgrp();
}

#define SYZ_HAVE_RESET_TEST 1
static void reset_test()
{
  int fd;
  for (fd = 3; fd < 30; fd++)
    close(fd);
}

struct thread_t {
  int created, call;
  event_t ready, done;
};

static struct thread_t threads[16];
static void execute_call(int call);
static int running;

static void* thr(void* arg)
{
  struct thread_t* th = (struct thread_t*)arg;
  for (;;) {
    event_wait(&th->ready);
    event_reset(&th->ready);
    execute_call(th->call);
    __atomic_fetch_sub(&running, 1, __ATOMIC_RELAXED);
    event_set(&th->done);
  }
  return 0;
}

static void execute_one(void)
{
  int i, call, thread;
  int collide = 0;
again:
  for (call = 0; call < 5; call++) {
    for (thread = 0; thread < (int)(sizeof(threads) / sizeof(threads[0]));
         thread++) {
      struct thread_t* th = &threads[thread];
      if (!th->created) {
        th->created = 1;
        event_init(&th->ready);
        event_init(&th->done);
        event_set(&th->done);
        thread_start(thr, th);
      }
      if (!event_isset(&th->done))
        continue;
      event_reset(&th->done);
      th->call = call;
      __atomic_fetch_add(&running, 1, __ATOMIC_RELAXED);
      event_set(&th->ready);
      if (collide && (call % 2) == 0)
        break;
      event_timedwait(&th->done, 45);
      break;
    }
  }
  for (i = 0; i < 100 && __atomic_load_n(&running, __ATOMIC_RELAXED); i++)
    sleep_ms(1);
  if (!collide) {
    collide = 1;
    goto again;
  }
}

static void execute_one(void);

#define WAIT_FLAGS __WALL

static void loop(void)
{
  int iter;
  for (iter = 0;; iter++) {
    char cwdbuf[32];
    sprintf(cwdbuf, "./%d", iter);
    if (mkdir(cwdbuf, 0777))
      exit(1);
    int pid = fork();
    if (pid < 0)
      exit(1);
    if (pid == 0) {
      if (chdir(cwdbuf))
        exit(1);
      setup_test();
      execute_one();
      reset_test();
      exit(0);
    }
    int status = 0;
    uint64_t start = current_time_ms();
    for (;;) {
      if (waitpid(-1, &status, WNOHANG | WAIT_FLAGS) == pid)
        break;
      sleep_ms(1);
      if (current_time_ms() - start < 5 * 1000)
        continue;
      kill_and_wait(pid, &status);
      break;
    }
    remove_dir(cwdbuf);
  }
}
#ifndef __NR_sched_setattr
#define __NR_sched_setattr 314
#endif

uint64_t r[1] = {0xffffffffffffffff};

void execute_call(int call)
{
  long res;
  switch (call) {
  case 0:
    memcpy((void*)0x20000040, "./bus\000", 6);
    res = syscall(__NR_open, 0x20000040, 0x1fe, 0);
    if (res != -1)
      r[0] = res;
    break;
  case 1:
    memcpy((void*)0x200001c0, "\x15\x8a\xdd\x00", 4);
    syscall(__NR_write, r[0], 0x200001c0, 4);
    break;
  case 2:
    *(uint32_t*)0x20000800 = 1;
    *(uint32_t*)0x20000804 = 0x70;
    *(uint8_t*)0x20000808 = 0;
    *(uint8_t*)0x20000809 = 0;
    *(uint8_t*)0x2000080a = 0;
    *(uint8_t*)0x2000080b = 0;
    *(uint32_t*)0x2000080c = 0;
    *(uint64_t*)0x20000810 = 0x50a;
    *(uint64_t*)0x20000818 = 0;
    *(uint64_t*)0x20000820 = 0;
    STORE_BY_BITMASK(uint64_t, , 0x20000828, 0, 0, 1);
    STORE_BY_BITMASK(uint64_t, , 0x20000828, 0, 1, 1);
    STORE_BY_BITMASK(uint64_t, , 0x20000828, 0, 2, 1);
    STORE_BY_BITMASK(uint64_t, , 0x20000828, 0, 3, 1);
    STORE_BY_BITMASK(uint64_t, , 0x20000828, 0, 4, 1);
    STORE_BY_BITMASK(uint64_t, , 0x20000828, 7, 5, 1);
    STORE_BY_BITMASK(uint64_t, , 0x20000828, 0, 6, 1);
    STORE_BY_BITMASK(uint64_t, , 0x20000828, 0, 7, 1);
    STORE_BY_BITMASK(uint64_t, , 0x20000828, 0, 8, 1);
    STORE_BY_BITMASK(uint64_t, , 0x20000828, 0, 9, 1);
    STORE_BY_BITMASK(uint64_t, , 0x20000828, 0, 10, 1);
    STORE_BY_BITMASK(uint64_t, , 0x20000828, 0, 11, 1);
    STORE_BY_BITMASK(uint64_t, , 0x20000828, 0, 12, 1);
    STORE_BY_BITMASK(uint64_t, , 0x20000828, 0, 13, 1);
    STORE_BY_BITMASK(uint64_t, , 0x20000828, 0x7fff, 14, 1);
    STORE_BY_BITMASK(uint64_t, , 0x20000828, 0, 15, 2);
    STORE_BY_BITMASK(uint64_t, , 0x20000828, 0, 17, 1);
    STORE_BY_BITMASK(uint64_t, , 0x20000828, 0, 18, 1);
    STORE_BY_BITMASK(uint64_t, , 0x20000828, 0, 19, 1);
    STORE_BY_BITMASK(uint64_t, , 0x20000828, 0, 20, 1);
    STORE_BY_BITMASK(uint64_t, , 0x20000828, 0, 21, 1);
    STORE_BY_BITMASK(uint64_t, , 0x20000828, 0, 22, 1);
    STORE_BY_BITMASK(uint64_t, , 0x20000828, 0, 23, 1);
    STORE_BY_BITMASK(uint64_t, , 0x20000828, 0, 24, 1);
    STORE_BY_BITMASK(uint64_t, , 0x20000828, 0, 25, 1);
    STORE_BY_BITMASK(uint64_t, , 0x20000828, 0, 26, 1);
    STORE_BY_BITMASK(uint64_t, , 0x20000828, 0, 27, 1);
    STORE_BY_BITMASK(uint64_t, , 0x20000828, 0, 28, 1);
    STORE_BY_BITMASK(uint64_t, , 0x20000828, 0, 29, 35);
    *(uint32_t*)0x20000830 = 0;
    *(uint32_t*)0x20000834 = 0;
    *(uint64_t*)0x20000838 = 0;
    *(uint64_t*)0x20000840 = 0;
    *(uint64_t*)0x20000848 = 0;
    *(uint64_t*)0x20000850 = 0;
    *(uint32_t*)0x20000858 = 0;
    *(uint32_t*)0x2000085c = 0;
    *(uint64_t*)0x20000860 = 0;
    *(uint32_t*)0x20000868 = 0xfffffffd;
    *(uint16_t*)0x2000086c = 0;
    *(uint16_t*)0x2000086e = 0;
    syscall(__NR_perf_event_open, 0x20000800, 0, -1, -1, 0);
    break;
  case 3:
    *(uint64_t*)0x20000000 = 0;
    syscall(__NR_sendfile, r[0], r[0], 0x20000000, 0x8080fffffffe);
    break;
#if 0
  case 4:
    *(uint32_t*)0x200002c0 = 0;
    *(uint32_t*)0x200002c4 = 2;
    *(uint64_t*)0x200002c8 = 0;
    *(uint32_t*)0x200002d0 = 0;
    *(uint32_t*)0x200002d4 = 3;
    *(uint64_t*)0x200002d8 = 0;
    *(uint64_t*)0x200002e0 = 0;
    *(uint64_t*)0x200002e8 = 0;
    syscall(__NR_sched_setattr, 0, 0x200002c0, 0);
    break;
#endif
  }
}
int main(void)
{
  syscall(__NR_mmap, 0x20000000, 0x1000000, 3, 0x32, -1, 0);
  for (procid = 0; procid < 6; procid++) {
    if (fork() == 0) {
      use_temporary_dir();
      loop();
    }
  }
  sleep(1000000);
  return 0;
}

^ permalink raw reply	[flat|nested] 9+ messages in thread

* INFO: rcu detected stall in ext4_file_write_iter
@ 2019-02-26  6:50 syzbot
  2019-02-26 15:17 ` Theodore Y. Ts'o
                   ` (2 more replies)
  0 siblings, 3 replies; 9+ messages in thread
From: syzbot @ 2019-02-26  6:50 UTC (permalink / raw)
  To: adilger.kernel, linux-ext4, linux-kernel, syzkaller-bugs, tytso

Hello,

syzbot found the following crash on:

HEAD commit:    8a61716ff2ab Merge tag 'ceph-for-5.0-rc8' of git://github...
git tree:       upstream
console output: https://syzkaller.appspot.com/x/log.txt?x=161b71d4c00000
kernel config:  https://syzkaller.appspot.com/x/.config?x=7132344728e7ec3f
dashboard link: https://syzkaller.appspot.com/bug?extid=7d19c5fe6a3f1161abb7
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=103908f8c00000
C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=105e5cd0c00000

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+7d19c5fe6a3f1161abb7@syzkaller.appspotmail.com

audit: type=1400 audit(1550814986.750:36): avc:  denied  { map } for   
pid=8058 comm="syz-executor004" path="/root/syz-executor004991115"  
dev="sda1" ino=1426 scontext=unconfined_u:system_r:insmod_t:s0-s0:c0.c1023  
tcontext=unconfined_u:object_r:user_home_t:s0 tclass=file permissive=1
hrtimer: interrupt took 42841 ns
rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
rcu: 	(detected by 1, t=10502 jiffies, g=5873, q=2)
rcu: All QSes seen, last rcu_preempt kthread activity 10502  
(4295059997-4295049495), jiffies_till_next_fqs=1, root ->qsmask 0x0
syz-executor004 R  running task    26448  8069   8060 0x00000000
Call Trace:
  <IRQ>
  sched_show_task kernel/sched/core.c:5306 [inline]
  sched_show_task.cold+0x292/0x30b kernel/sched/core.c:5281
  print_other_cpu_stall kernel/rcu/tree.c:1301 [inline]
  check_cpu_stall kernel/rcu/tree.c:1429 [inline]
  rcu_pending kernel/rcu/tree.c:3018 [inline]
  rcu_check_callbacks.cold+0xa10/0xa4a kernel/rcu/tree.c:2521
  update_process_times+0x32/0x80 kernel/time/timer.c:1635
  tick_sched_handle+0xa2/0x190 kernel/time/tick-sched.c:161
  tick_sched_timer+0x47/0x130 kernel/time/tick-sched.c:1271
  __run_hrtimer kernel/time/hrtimer.c:1389 [inline]
  __hrtimer_run_queues+0x33e/0xde0 kernel/time/hrtimer.c:1451
  hrtimer_interrupt+0x314/0x770 kernel/time/hrtimer.c:1509
  local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1035 [inline]
  smp_apic_timer_interrupt+0x120/0x570 arch/x86/kernel/apic/apic.c:1060
  apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:807
  </IRQ>
RIP: 0010:__sanitizer_cov_trace_pc+0x0/0x50 kernel/kcov.c:94
Code: e5 08 41 bc f4 ff ff ff e8 11 9f ea ff 48 c7 05 12 fb e5 08 00 00 00  
00 e9 c8 e9 ff ff 90 90 90 90 90 90 90 90 90 90 90 90 90 <55> 48 89 e5 48  
8b 75 08 65 48 8b 04 25 40 ee 01 00 65 8b 15 38 0c
RSP: 0018:ffff888084ed72c0 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff13
RAX: dffffc0000000000 RBX: ffff88809a2205c0 RCX: ffffffff81e7c36c
RDX: 1ffff11013444114 RSI: ffffffff81e7c37a RDI: ffff88809a2208a0
RBP: ffff888084ed7300 R08: ffff88808fa28240 R09: ffffed1015d25bd0
R10: ffffed1015d25bcf R11: ffff8880ae92de7b R12: 0000000000000002
R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000001
  __ext4_journal_start fs/ext4/ext4_jbd2.h:311 [inline]
  ext4_dirty_inode+0x64/0xc0 fs/ext4/inode.c:6081
  __mark_inode_dirty+0x919/0x1290 fs/fs-writeback.c:2155
  mark_inode_dirty include/linux/fs.h:2125 [inline]
  __generic_write_end+0x1b9/0x240 fs/buffer.c:2118
  generic_write_end+0x6c/0x90 fs/buffer.c:2163
  ext4_da_write_end+0x3c8/0xa50 fs/ext4/inode.c:3204
  generic_perform_write+0x2f0/0x530 mm/filemap.c:3219
  __generic_file_write_iter+0x25e/0x630 mm/filemap.c:3333
  ext4_file_write_iter+0x33f/0x1160 fs/ext4/file.c:266
  call_write_iter include/linux/fs.h:1863 [inline]
  do_iter_readv_writev+0x5e0/0x8e0 fs/read_write.c:680
  do_iter_write fs/read_write.c:956 [inline]
  do_iter_write+0x184/0x610 fs/read_write.c:937
  vfs_iter_write+0x77/0xb0 fs/read_write.c:969
  iter_file_splice_write+0x667/0xbe0 fs/splice.c:749
  do_splice_from fs/splice.c:851 [inline]
  direct_splice_actor+0x126/0x1a0 fs/splice.c:1023
  splice_direct_to_actor+0x369/0x970 fs/splice.c:978
  do_splice_direct+0x1da/0x2a0 fs/splice.c:1066
  do_sendfile+0x597/0xd00 fs/read_write.c:1436
  __do_sys_sendfile64 fs/read_write.c:1491 [inline]
  __se_sys_sendfile64 fs/read_write.c:1483 [inline]
  __x64_sys_sendfile64+0x15a/0x220 fs/read_write.c:1483
  do_syscall_64+0x103/0x610 arch/x86/entry/common.c:290
  entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x446a59
Code: e8 dc e6 ff ff 48 83 c4 18 c3 0f 1f 80 00 00 00 00 48 89 f8 48 89 f7  
48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff  
ff 0f 83 4b 07 fc ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007fce454e5db8 EFLAGS: 00000246 ORIG_RAX: 0000000000000028
RAX: ffffffffffffffda RBX: 00000000006dcc28 RCX: 0000000000446a59
RDX: 0000000020000000 RSI: 0000000000000003 RDI: 0000000000000003
RBP: 00000000006dcc20 R08: 0000000000000000 R09: 0000000000000000
R10: 00008080fffffffe R11: 0000000000000246 R12: 00000000006dcc2c
R13: 00007ffd7bf04daf R14: 00007fce454e69c0 R15: 20c49ba5e353f7cf
rcu: rcu_preempt kthread starved for 10502 jiffies! g5873 f0x2  
RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=1
rcu: RCU grace-period kthread stack dump:
rcu_preempt     R  running task    29200    10      2 0x80000000
Call Trace:
  context_switch kernel/sched/core.c:2844 [inline]
  __schedule+0x817/0x1cc0 kernel/sched/core.c:3485
  schedule+0x92/0x180 kernel/sched/core.c:3529
  schedule_timeout+0x4db/0xfd0 kernel/time/timer.c:1803
  rcu_gp_fqs_loop kernel/rcu/tree.c:1948 [inline]
  rcu_gp_kthread+0x956/0x17a0 kernel/rcu/tree.c:2105
  kthread+0x357/0x430 kernel/kthread.c:246
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352


---
This bug is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at syzkaller@googlegroups.com.

syzbot will keep track of this bug report. See:
https://goo.gl/tpsmEJ#bug-status-tracking for how to communicate with  
syzbot.
syzbot can test patches for this bug, for details see:
https://goo.gl/tpsmEJ#testing-patches

^ permalink raw reply	[flat|nested] 9+ messages in thread

end of thread, other threads:[~2021-10-06  8:20 UTC | newest]

Thread overview: 9+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-10-06  8:20 INFO: rcu detected stall in ext4_file_write_iter Hao Sun
  -- strict thread matches above, loose matches on Subject: below --
2019-02-26  6:50 syzbot
2019-02-26 15:17 ` Theodore Y. Ts'o
2019-02-27  9:58   ` Dmitry Vyukov
2019-02-27 21:57     ` Theodore Y. Ts'o
2019-02-28  9:34       ` Dmitry Vyukov
2019-03-21 17:30 ` syzbot
2020-09-11 19:33 ` syzbot
2020-09-11 20:03   ` Jens Axboe

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).