syzbot


INFO: rcu detected stall in sys_close (2)

Status: auto-closed as invalid on 2022/08/21 03:13
Reported-by: syzbot+@syzkaller.appspotmail.com
First crash: 237d, last: 187d
similar bugs (2):
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: rcu detected stall in sys_close (3) 1 92d 92d 0/24 auto-obsoleted due to no activity on 2022/10/25 14:50
upstream INFO: rcu detected stall in sys_close 1 330d 330d 0/24 closed as invalid on 2022/02/08 10:10

Sample crash report:
rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
rcu: 	1-...!: (1 GPs behind) idle=ca1/1/0x4000000000000000 softirq=98668/98669 fqs=0 
rcu: 	Tasks blocked on level-0 rcu_node (CPUs 0-1): P16877/1:b..l
	(detected by 0, t=10506 jiffies, g=137217, q=33)
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 22325 Comm: syz-executor.5 Not tainted 5.18.0-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:bytes_is_nonzero mm/kasan/generic.c:85 [inline]
RIP: 0010:memory_is_nonzero mm/kasan/generic.c:102 [inline]
RIP: 0010:memory_is_poisoned_n mm/kasan/generic.c:128 [inline]
RIP: 0010:memory_is_poisoned mm/kasan/generic.c:159 [inline]
RIP: 0010:check_region_inline mm/kasan/generic.c:180 [inline]
RIP: 0010:kasan_check_range+0xdb/0x180 mm/kasan/generic.c:189
Code: 80 38 00 74 f2 48 89 c2 b8 01 00 00 00 48 85 d2 75 56 5b 5d 41 5c c3 48 85 d2 74 5e 48 01 ea eb 09 48 83 c0 01 48 39 d0 74 50 <80> 38 00 74 f2 eb d4 41 bc 08 00 00 00 48 89 ea 45 29 dc 4d 8d 1c
RSP: 0018:ffffc900003f8c50 EFLAGS: 00000082
RAX: fffff5200007f193 RBX: fffff5200007f194 RCX: ffffffff815d57a0
RDX: fffff5200007f194 RSI: 0000000000000004 RDI: ffffc900003f8c98
RBP: fffff5200007f193 R08: 0000000000000001 R09: ffffc900003f8c9b
R10: fffff5200007f193 R11: 0000000000000001 R12: ffffffff90829698
R13: ffffffff908296a0 R14: 1ffff9200007f1a7 R15: ffffffff89ce4860
FS:  0000555555662400(0000) GS:ffff8880b9d00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f7f5139c028 CR3: 0000000078ebd000 CR4: 00000000003506e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <IRQ>
 instrument_atomic_read_write include/linux/instrumented.h:101 [inline]
 atomic_try_cmpxchg_acquire include/linux/atomic/atomic-instrumented.h:542 [inline]
 queued_spin_lock include/asm-generic/qspinlock.h:82 [inline]
 do_raw_spin_lock+0x120/0x2a0 kernel/locking/spinlock_debug.c:115
 __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:111 [inline]
 _raw_spin_lock_irqsave+0x41/0x50 kernel/locking/spinlock.c:162
 debug_object_activate+0x12e/0x3e0 lib/debugobjects.c:661
 debug_hrtimer_activate kernel/time/hrtimer.c:420 [inline]
 debug_activate kernel/time/hrtimer.c:475 [inline]
 enqueue_hrtimer+0x27/0x3e0 kernel/time/hrtimer.c:1084
 __run_hrtimer kernel/time/hrtimer.c:1702 [inline]
 __hrtimer_run_queues+0xb02/0xe50 kernel/time/hrtimer.c:1749
 hrtimer_interrupt+0x31c/0x790 kernel/time/hrtimer.c:1811
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1086 [inline]
 __sysvec_apic_timer_interrupt+0x146/0x530 arch/x86/kernel/apic/apic.c:1103
 sysvec_apic_timer_interrupt+0x8e/0xc0 arch/x86/kernel/apic/apic.c:1097
 </IRQ>
 <TASK>
 asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:645
RIP: 0010:filp_close+0x41/0x160 fs/open.c:1317
Code: 00 00 00 4c 89 ef e8 7e 91 f3 ff 4c 89 ea 48 b8 00 00 00 00 00 fc ff df 48 c1 ea 03 80 3c 02 00 0f 85 11 01 00 00 48 8b 5d 70 <31> ff 48 89 de e8 45 9a a8 ff 48 85 db 0f 84 0a ab 5a 07 e8 a7 97
RSP: 0018:ffffc90004da7ee8 EFLAGS: 00000246
RAX: dffffc0000000000 RBX: 0000000000000019 RCX: ffffffff81cfddb2
RDX: 1ffff11004715866 RSI: 0000000000000008 RDI: ffff8880238ac330
RBP: ffff8880238ac2c0 R08: 0000000000000000 R09: ffff8880238ac337
R10: ffffed1004715866 R11: 0000000000000001 R12: ffff88801a5e53c0
R13: ffff8880238ac330 R14: 0000000000000000 R15: 0000000000000000
 close_fd+0x6f/0xa0 fs/file.c:671
 __do_sys_close fs/open.c:1342 [inline]
 __se_sys_close fs/open.c:1340 [inline]
 __x64_sys_close+0x2f/0xa0 fs/open.c:1340
 do_syscall_x64 arch/x86/entry/common.c:50 [inline]
 do_syscall_64+0x35/0xb0 arch/x86/entry/common.c:80
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f7f5123bd2b
Code: 0f 05 48 3d 00 f0 ff ff 77 45 c3 0f 1f 40 00 48 83 ec 18 89 7c 24 0c e8 63 fc ff ff 8b 7c 24 0c 41 89 c0 b8 03 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 35 44 89 c7 89 44 24 0c e8 a1 fc ff ff 8b 44
RSP: 002b:00007fff2a8e7b90 EFLAGS: 00000293 ORIG_RAX: 0000000000000003
RAX: ffffffffffffffda RBX: 0000000000000015 RCX: 00007f7f5123bd2b
RDX: ffffffffffffffb8 RSI: ffffffffffffffff RDI: 0000000000000014
RBP: 00007f7f5139d960 R08: 0000000000000000 R09: 00007f7f513a0348
R10: 00007fff2a8e7c90 R11: 0000000000000293 R12: 0000000000140c37
R13: 00007fff2a8e7c90 R14: 00007f7f5139bf60 R15: 0000000000000032
 </TASK>
task:kworker/u4:20   state:R  running task     stack:26872 pid:16877 ppid:     2 flags:0x00004000
Workqueue: bat_events batadv_nc_worker
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5073 [inline]
 __schedule+0xa9a/0x4cc0 kernel/sched/core.c:6388
 preempt_schedule_irq+0x4e/0x90 kernel/sched/core.c:6696
 irqentry_exit+0x31/0x80 kernel/entry/common.c:428
 asm_sysvec_reschedule_ipi+0x12/0x20 arch/x86/include/asm/idtentry.h:650
RIP: 0010:lock_acquire+0x69/0x510 kernel/locking/lockdep.c:5609
Code: 03 48 c7 44 24 18 35 6e 5c 8b 48 01 d8 48 c7 44 24 20 70 e2 5c 81 c7 00 f1 f1 f1 f1 c7 40 04 f1 f1 00 00 c7 40 08 00 00 00 f3 <c7> 40 0c f3 f3 f3 f3 65 48 8b 04 25 28 00 00 00 48 89 84 24 a8 00
RSP: 0018:ffffc90004477b98 EFLAGS: 00000282
RAX: fffff5200088ef75 RBX: 1ffff9200088ef75 RCX: 0000000000000002
RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffff8bd7f5e0
RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000
R10: ffffffff890773f1 R11: 0000000000000000 R12: 0000000000000002
R13: 0000000000000000 R14: ffffffff8bd7f5e0 R15: 0000000000000000
 rcu_lock_acquire include/linux/rcupdate.h:268 [inline]
 rcu_read_lock include/linux/rcupdate.h:694 [inline]
 batadv_nc_purge_orig_hash net/batman-adv/network-coding.c:408 [inline]
 batadv_nc_worker+0x12d/0xfa0 net/batman-adv/network-coding.c:719
 process_one_work+0x996/0x1610 kernel/workqueue.c:2289
 worker_thread+0x665/0x1080 kernel/workqueue.c:2436
 kthread+0x2e9/0x3a0 kernel/kthread.c:376
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:298
 </TASK>
rcu: rcu_preempt kthread timer wakeup didn't happen for 10505 jiffies! g137217 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402
rcu: 	Possible timer handling issue on cpu=0 timer-softirq=60317
rcu: rcu_preempt kthread starved for 10506 jiffies! g137217 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402 ->cpu=0
rcu: 	Unless rcu_preempt kthread gets sufficient CPU time, OOM is now expected behavior.
rcu: RCU grace-period kthread stack dump:
task:rcu_preempt     state:I stack:28448 pid:   16 ppid:     2 flags:0x00004000
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5073 [inline]
 __schedule+0xa9a/0x4cc0 kernel/sched/core.c:6388
 schedule+0xd2/0x1f0 kernel/sched/core.c:6460
 schedule_timeout+0x14a/0x2a0 kernel/time/timer.c:1884
 rcu_gp_fqs_loop+0x186/0x810 kernel/rcu/tree.c:1971
 rcu_gp_kthread+0x1de/0x320 kernel/rcu/tree.c:2144
 kthread+0x2e9/0x3a0 kernel/kthread.c:376
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:298
 </TASK>
rcu: Stack dump where RCU GP kthread last ran:
NMI backtrace for cpu 0
CPU: 0 PID: 22053 Comm: udevd Not tainted 5.18.0-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 <IRQ>
 __dump_stack lib/dump_stack.c:88 [inline]
 dump_stack_lvl+0xcd/0x134 lib/dump_stack.c:106
 nmi_cpu_backtrace.cold+0x47/0x144 lib/nmi_backtrace.c:111
 nmi_trigger_cpumask_backtrace+0x1e6/0x230 lib/nmi_backtrace.c:62
 trigger_single_cpu_backtrace include/linux/nmi.h:164 [inline]
 rcu_check_gp_kthread_starvation.cold+0x1fb/0x200 kernel/rcu/tree_stall.h:490
 print_other_cpu_stall kernel/rcu/tree_stall.h:595 [inline]
 check_cpu_stall kernel/rcu/tree_stall.h:741 [inline]
 rcu_pending kernel/rcu/tree.c:3923 [inline]
 rcu_sched_clock_irq+0x1f7c/0x2150 kernel/rcu/tree.c:2625
 update_process_times+0x16d/0x200 kernel/time/timer.c:1788
 tick_sched_handle+0x9b/0x180 kernel/time/tick-sched.c:243
 tick_sched_timer+0xee/0x120 kernel/time/tick-sched.c:1473
 __run_hrtimer kernel/time/hrtimer.c:1685 [inline]
 __hrtimer_run_queues+0x1c0/0xe50 kernel/time/hrtimer.c:1749
 hrtimer_interrupt+0x31c/0x790 kernel/time/hrtimer.c:1811
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1086 [inline]
 __sysvec_apic_timer_interrupt+0x146/0x530 arch/x86/kernel/apic/apic.c:1103
 sysvec_apic_timer_interrupt+0x8e/0xc0 arch/x86/kernel/apic/apic.c:1097
 </IRQ>
 <TASK>
 asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:645
RIP: 0010:csd_lock_wait kernel/smp.c:411 [inline]
RIP: 0010:smp_call_function_many_cond+0x499/0x1110 kernel/smp.c:969
Code: 01 89 ee e8 99 d2 0b 00 85 ed 74 47 48 8b 04 24 49 89 c4 83 e0 07 49 c1 ec 03 48 89 c5 4d 01 fc 83 c5 03 e8 59 d0 0b 00 f3 90 <41> 0f b6 04 24 40 38 c5 7c 08 84 c0 0f 85 21 0a 00 00 8b 43 08 31
RSP: 0018:ffffc900034efbc8 EFLAGS: 00000293
RAX: 0000000000000000 RBX: ffff8880b9d3f7a0 RCX: 0000000000000000
RDX: ffff88802670a140 RSI: ffffffff816ca537 RDI: 0000000000000003
RBP: 0000000000000003 R08: 0000000000000000 R09: 0000000000000001
R10: ffffffff816ca55d R11: 0000000000000000 R12: ffffed10173a7ef5
R13: 0000000000000001 R14: 0000000000000001 R15: dffffc0000000000
 on_each_cpu_cond_mask+0x56/0xa0 kernel/smp.c:1135
 kill_bdev block/bdev.c:76 [inline]
 blkdev_flush_mapping+0x185/0x3c0 block/bdev.c:656
 blkdev_put_whole block/bdev.c:687 [inline]
 blkdev_put+0x706/0x950 block/bdev.c:947
 blkdev_close+0x64/0x80 block/fops.c:512
 __fput+0x277/0x9d0 fs/file_table.c:317
 task_work_run+0xdd/0x1a0 kernel/task_work.c:164
 resume_user_mode_work include/linux/resume_user_mode.h:49 [inline]
 exit_to_user_mode_loop kernel/entry/common.c:169 [inline]
 exit_to_user_mode_prepare+0x23c/0x250 kernel/entry/common.c:201
 __syscall_exit_to_user_mode_work kernel/entry/common.c:283 [inline]
 syscall_exit_to_user_mode+0x19/0x60 kernel/entry/common.c:294
 do_syscall_64+0x42/0xb0 arch/x86/entry/common.c:86
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7fefda98cfc3
Code: 48 ff ff ff b8 ff ff ff ff e9 3e ff ff ff 66 0f 1f 84 00 00 00 00 00 64 8b 04 25 18 00 00 00 85 c0 75 14 b8 03 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 45 c3 0f 1f 40 00 48 83 ec 18 89 7c 24 0c e8
RSP: 002b:00007ffffd1cbe18 EFLAGS: 00000246 ORIG_RAX: 0000000000000003
RAX: 0000000000000000 RBX: 00007fefda8916a8 RCX: 00007fefda98cfc3
RDX: 000000000000001c RSI: 00007ffffd1cb618 RDI: 0000000000000008
RBP: 00005600ce7f5fe0 R08: 0000000000000007 R09: 00005600ce7f7c40
R10: 00007fefdaa1bfc0 R11: 0000000000000246 R12: 0000000000000002
R13: 00005600ce7e0a20 R14: 0000000000000008 R15: 00005600ce7c22c0
 </TASK>
----------------
Code disassembly (best guess):
   0:	80 38 00             	cmpb   $0x0,(%rax)
   3:	74 f2                	je     0xfffffff7
   5:	48 89 c2             	mov    %rax,%rdx
   8:	b8 01 00 00 00       	mov    $0x1,%eax
   d:	48 85 d2             	test   %rdx,%rdx
  10:	75 56                	jne    0x68
  12:	5b                   	pop    %rbx
  13:	5d                   	pop    %rbp
  14:	41 5c                	pop    %r12
  16:	c3                   	retq
  17:	48 85 d2             	test   %rdx,%rdx
  1a:	74 5e                	je     0x7a
  1c:	48 01 ea             	add    %rbp,%rdx
  1f:	eb 09                	jmp    0x2a
  21:	48 83 c0 01          	add    $0x1,%rax
  25:	48 39 d0             	cmp    %rdx,%rax
  28:	74 50                	je     0x7a
* 2a:	80 38 00             	cmpb   $0x0,(%rax) <-- trapping instruction
  2d:	74 f2                	je     0x21
  2f:	eb d4                	jmp    0x5
  31:	41 bc 08 00 00 00    	mov    $0x8,%r12d
  37:	48 89 ea             	mov    %rbp,%rdx
  3a:	45 29 dc             	sub    %r11d,%r12d
  3d:	4d                   	rex.WRB
  3e:	8d                   	.byte 0x8d
  3f:	1c                   	.byte 0x1c

Crashes (3):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci-upstream-kasan-gce-selinux-root 2022/05/23 03:12 upstream 4b0986a3613c 7268fa62 .config log report info INFO: rcu detected stall in sys_close
ci-upstream-kasan-gce-smack-root 2022/05/20 17:05 upstream 3d7285a335ed bd37ad7e .config log report info INFO: rcu detected stall in sys_close
ci-upstream-kasan-gce-smack-root 2022/04/03 06:08 upstream be2d3ecedd99 79a2a8fc .config log report info INFO: rcu detected stall in sys_close
* Struck through repros no longer work on HEAD.