syzbot


INFO: rcu detected stall in nsim_dev_trap_report_work

Status: upstream: reported on 2024/06/13 10:37
Reported-by: syzbot+ac9f4557c0561d305bce@syzkaller.appspotmail.com
First crash: 6d08h, last: 6d08h
Similar bugs (3)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: rcu detected stall in nsim_dev_trap_report_work (2) net syz done 5 10d 231d 0/27 upstream: reported syz repro on 2023/11/01 08:50
upstream INFO: rcu detected stall in nsim_dev_trap_report_work net syz 4 286d 329d 23/27 fixed on 2023/10/12 12:48
linux-6.1 INFO: rcu detected stall in nsim_dev_trap_report_work 2 36d 81d 0/3 upstream: reported on 2024/03/30 02:24

Sample crash report:
rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
rcu: 	1-...!: (0 ticks this GP) idle=b87/1/0x4000000000000000 softirq=25725/25725 fqs=0 
rcu: 	Tasks blocked on level-0 rcu_node (CPUs 0-1): P3574/1:b..l
	(detected by 0, t=10505 jiffies, g=40197, q=5)
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 26 Comm: kworker/1:1 Not tainted 5.15.160-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/07/2024
Workqueue: events nsim_dev_trap_report_work
RIP: 0010:match_held_lock+0x77/0xb0 kernel/locking/lockdep.c:5102
Code: c7 c2 c0 df 8e 8f 48 29 d0 48 c1 f8 06 48 ba ab aa aa aa aa aa aa aa 48 0f af d0 bd 01 00 00 00 48 39 ca 74 02 31 ed 89 e8 5b <5d> c3 e8 02 ae e7 f9 31 ed 85 c0 74 f0 83 3d dd a6 c6 03 00 75 e7
RSP: 0000:ffffc90000dd0b50 EFLAGS: 00000046
RAX: 0000000000000001 RBX: 0000000000000005 RCX: ffffc90000dd0b03
RDX: 1ffff920001ba17c RSI: ffffffff916a2af8 RDI: ffff888011e58bb8
RBP: 0000000000000001 R08: dffffc0000000000 R09: fffffbfff1bc8cce
R10: 0000000000000000 R11: dffffc0000000001 R12: 0000000000000005
R13: 0000000000000019 R14: ffff888011e58af0 R15: ffff888011e58bb8
FS:  0000000000000000(0000) GS:ffff8880b9b00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 000000002001e000 CR3: 0000000015b97000 CR4: 00000000003506e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <NMI>
 </NMI>
 <IRQ>
 find_held_lock kernel/locking/lockdep.c:5115 [inline]
 __lock_release kernel/locking/lockdep.c:5300 [inline]
 lock_release+0x245/0x9a0 kernel/locking/lockdep.c:5643
 __raw_spin_unlock_irqrestore include/linux/spinlock_api_smp.h:158 [inline]
 _raw_spin_unlock_irqrestore+0x75/0x130 kernel/locking/spinlock.c:194
 debug_hrtimer_deactivate kernel/time/hrtimer.c:425 [inline]
 debug_deactivate+0x1b/0x1e0 kernel/time/hrtimer.c:481
 __run_hrtimer kernel/time/hrtimer.c:1654 [inline]
 __hrtimer_run_queues+0x31d/0xcf0 kernel/time/hrtimer.c:1750
 hrtimer_interrupt+0x392/0x980 kernel/time/hrtimer.c:1812
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1085 [inline]
 __sysvec_apic_timer_interrupt+0x139/0x470 arch/x86/kernel/apic/apic.c:1102
 sysvec_apic_timer_interrupt+0x8c/0xb0 arch/x86/kernel/apic/apic.c:1096
 </IRQ>
 <TASK>
 asm_sysvec_apic_timer_interrupt+0x16/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 55 41 57 41 56 41 55 41 54 53 48 83 ec
RSP: 0000:ffffc90000e1f5a8 EFLAGS: 00010246
RAX: 0000000000000000 RBX: 1ffff110023cb2f1 RCX: 0000000000000240
RDX: 0000000000000000 RSI: 0000000000000008 RDI: ffff88807d4d7dc0
RBP: ffff888011e59788 R08: dffffc0000000000 R09: ffffed100fa9a000
R10: 0000000000000000 R11: dffffc0000000001 R12: dffffc0000000000
R13: 0000000000000001 R14: ffff88807d4d7000 R15: fffa80007d4d0000
 clear_page arch/x86/include/asm/page_64.h:49 [inline]
 clear_highpage include/linux/highmem.h:181 [inline]
 kernel_init_free_pages+0x7d/0xf0 mm/page_alloc.c:1278
 post_alloc_hook+0x104/0x220 mm/page_alloc.c:2416
 prep_new_page mm/page_alloc.c:2426 [inline]
 get_page_from_freelist+0x322a/0x33c0 mm/page_alloc.c:4159
 __alloc_pages+0x272/0x700 mm/page_alloc.c:5423
 alloc_slab_page mm/slub.c:1775 [inline]
 allocate_slab mm/slub.c:1912 [inline]
 new_slab+0xbb/0x4b0 mm/slub.c:1975
 ___slab_alloc+0x6f6/0xe10 mm/slub.c:3008
 __slab_alloc mm/slub.c:3095 [inline]
 slab_alloc_node mm/slub.c:3186 [inline]
 __kmalloc_node_track_caller+0x1f6/0x390 mm/slub.c:4958
 kmalloc_reserve net/core/skbuff.c:356 [inline]
 __alloc_skb+0x12c/0x590 net/core/skbuff.c:427
 alloc_skb include/linux/skbuff.h:1167 [inline]
 nsim_dev_trap_skb_build drivers/net/netdevsim/dev.c:664 [inline]
 nsim_dev_trap_report drivers/net/netdevsim/dev.c:721 [inline]
 nsim_dev_trap_report_work+0x25e/0xab0 drivers/net/netdevsim/dev.c:762
 process_one_work+0x8a1/0x10c0 kernel/workqueue.c:2310
 worker_thread+0xaca/0x1280 kernel/workqueue.c:2457
 kthread+0x3f6/0x4f0 kernel/kthread.c:334
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:300
 </TASK>
task:kworker/u4:5    state:R  running task     stack:21144 pid: 3574 ppid:     2 flags:0x00004000
Workqueue: bat_events batadv_nc_worker
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5030 [inline]
 __schedule+0x12c4/0x45b0 kernel/sched/core.c:6376
 preempt_schedule_irq+0xf7/0x1c0 kernel/sched/core.c:6780
 irqentry_exit+0x53/0x80 kernel/entry/common.c:432
 asm_sysvec_reschedule_ipi+0x16/0x20 arch/x86/include/asm/idtentry.h:643
RIP: 0010:lock_acquire+0xec/0x4f0 kernel/locking/lockdep.c:5596
Code: be 08 00 00 00 e8 f4 7f 67 00 89 d8 48 0f a3 05 f2 b9 81 0c 73 0d e8 d3 67 08 00 84 c0 0f 84 b9 02 00 00 48 c7 c0 04 9a e4 8d <48> c1 e8 03 42 0f b6 04 28 84 c0 0f 85 dd 02 00 00 83 3d 60 ed 81
RSP: 0000:ffffc90003187a20 EFLAGS: 00000202
RAX: ffffffff8de49a04 RBX: 0000000000000001 RCX: ffffffff8162ac6c
RDX: 0000000000000000 RSI: ffffffff8ad8f6a0 RDI: ffffffff8ad8f660
RBP: ffffc90003187b70 R08: dffffc0000000000 R09: fffffbfff1bc8cce
R10: 0000000000000000 R11: dffffc0000000001 R12: 1ffff92000630f4c
R13: dffffc0000000000 R14: 0000000000000000 R15: ffffffff89fbba50
 rcu_lock_acquire+0x2a/0x30 include/linux/rcupdate.h:312
 rcu_read_lock include/linux/rcupdate.h:739 [inline]
 batadv_nc_process_nc_paths+0xb8/0x350 net/batman-adv/network-coding.c:691
 batadv_nc_worker+0x3d4/0x5b0 net/batman-adv/network-coding.c:732
 process_one_work+0x8a1/0x10c0 kernel/workqueue.c:2310
 worker_thread+0xaca/0x1280 kernel/workqueue.c:2457
 kthread+0x3f6/0x4f0 kernel/kthread.c:334
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:300
 </TASK>
rcu: rcu_preempt kthread timer wakeup didn't happen for 10504 jiffies! g40197 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402
rcu: 	Possible timer handling issue on cpu=1 timer-softirq=26331
rcu: rcu_preempt kthread starved for 10505 jiffies! g40197 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402 ->cpu=1
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:27192 pid:   15 ppid:     2 flags:0x00004000
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:5030 [inline]
 __schedule+0x12c4/0x45b0 kernel/sched/core.c:6376
 schedule+0x11b/0x1f0 kernel/sched/core.c:6459
 schedule_timeout+0x1b9/0x300 kernel/time/timer.c:1914
 rcu_gp_fqs_loop+0x2bf/0x1080 kernel/rcu/tree.c:1972
 rcu_gp_kthread+0xa4/0x360 kernel/rcu/tree.c:2145
 kthread+0x3f6/0x4f0 kernel/kthread.c:334
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:300
 </TASK>
rcu: Stack dump where RCU GP kthread last ran:
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 26 Comm: kworker/1:1 Not tainted 5.15.160-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 06/07/2024
Workqueue: events nsim_dev_trap_report_work
RIP: 0010:task_irq_context kernel/locking/lockdep.c:4520 [inline]
RIP: 0010:__lock_acquire+0x3b3/0x1ff0 kernel/locking/lockdep.c:4950
Code: 6c 24 18 74 12 48 89 df e8 ea 75 67 00 48 ba 00 00 00 00 00 fc ff df 48 8b 84 24 c0 00 00 00 48 89 9c 24 80 00 00 00 48 89 03 <65> 8b 05 aa c0 9f 7e 31 db 85 c0 0f 95 c3 01 db 48 8d bd d4 0a 00
RSP: 0000:ffffc90000dd0a00 EFLAGS: 00000046
RAX: 0000000000000000 RBX: ffff888011e58bd0 RCX: ffff888011e58af0
RDX: dffffc0000000000 RSI: 0000000000000000 RDI: ffffffff916a2af8
RBP: ffff888011e58000 R08: 0000000000000001 R09: 0000000000000001
R10: 0000000000000000 R11: dffffc0000000001 R12: 0000000000000000
R13: 0000000000000019 R14: 0000000000000019 R15: 0000000000000000
FS:  0000000000000000(0000) GS:ffff8880b9b00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 000000002001e000 CR3: 0000000015b97000 CR4: 00000000003506e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <NMI>
 </NMI>
 <IRQ>
 lock_acquire+0x1db/0x4f0 kernel/locking/lockdep.c:5623
 __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
 _raw_spin_lock_irqsave+0xd1/0x120 kernel/locking/spinlock.c:162
 debug_object_deactivate+0x63/0x380 lib/debugobjects.c:748
 debug_hrtimer_deactivate kernel/time/hrtimer.c:425 [inline]
 debug_deactivate+0x1b/0x1e0 kernel/time/hrtimer.c:481
 __run_hrtimer kernel/time/hrtimer.c:1654 [inline]
 __hrtimer_run_queues+0x31d/0xcf0 kernel/time/hrtimer.c:1750
 hrtimer_interrupt+0x392/0x980 kernel/time/hrtimer.c:1812
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1085 [inline]
 __sysvec_apic_timer_interrupt+0x139/0x470 arch/x86/kernel/apic/apic.c:1102
 sysvec_apic_timer_interrupt+0x8c/0xb0 arch/x86/kernel/apic/apic.c:1096
 </IRQ>
 <TASK>
 asm_sysvec_apic_timer_interrupt+0x16/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 55 41 57 41 56 41 55 41 54 53 48 83 ec
RSP: 0000:ffffc90000e1f5a8 EFLAGS: 00010246
RAX: 0000000000000000 RBX: 1ffff110023cb2f1 RCX: 0000000000000240
RDX: 0000000000000000 RSI: 0000000000000008 RDI: ffff88807d4d7dc0
RBP: ffff888011e59788 R08: dffffc0000000000 R09: ffffed100fa9a000
R10: 0000000000000000 R11: dffffc0000000001 R12: dffffc0000000000
R13: 0000000000000001 R14: ffff88807d4d7000 R15: fffa80007d4d0000
 clear_page arch/x86/include/asm/page_64.h:49 [inline]
 clear_highpage include/linux/highmem.h:181 [inline]
 kernel_init_free_pages+0x7d/0xf0 mm/page_alloc.c:1278
 post_alloc_hook+0x104/0x220 mm/page_alloc.c:2416
 prep_new_page mm/page_alloc.c:2426 [inline]
 get_page_from_freelist+0x322a/0x33c0 mm/page_alloc.c:4159
 __alloc_pages+0x272/0x700 mm/page_alloc.c:5423
 alloc_slab_page mm/slub.c:1775 [inline]
 allocate_slab mm/slub.c:1912 [inline]
 new_slab+0xbb/0x4b0 mm/slub.c:1975
 ___slab_alloc+0x6f6/0xe10 mm/slub.c:3008
 __slab_alloc mm/slub.c:3095 [inline]
 slab_alloc_node mm/slub.c:3186 [inline]
 __kmalloc_node_track_caller+0x1f6/0x390 mm/slub.c:4958
 kmalloc_reserve net/core/skbuff.c:356 [inline]
 __alloc_skb+0x12c/0x590 net/core/skbuff.c:427
 alloc_skb include/linux/skbuff.h:1167 [inline]
 nsim_dev_trap_skb_build drivers/net/netdevsim/dev.c:664 [inline]
 nsim_dev_trap_report drivers/net/netdevsim/dev.c:721 [inline]
 nsim_dev_trap_report_work+0x25e/0xab0 drivers/net/netdevsim/dev.c:762
 process_one_work+0x8a1/0x10c0 kernel/workqueue.c:2310
 worker_thread+0xaca/0x1280 kernel/workqueue.c:2457
 kthread+0x3f6/0x4f0 kernel/kthread.c:334
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:300
 </TASK>

Crashes (1):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2024/06/13 10:36 linux-5.15.y c61bd26ae81a 2aa5052f .config console log report info [disk image] [vmlinux] [kernel image] ci2-linux-5-15-kasan INFO: rcu detected stall in nsim_dev_trap_report_work
* Struck through repros no longer work on HEAD.