syzbot


INFO: rcu detected stall in inet_release (2)

Status: closed as invalid on 2022/02/08 10:10
Reported-by: syzbot+@syzkaller.appspotmail.com
First crash: 294d, last: 294d
similar bugs (2):
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: rcu detected stall in inet_release 1 1177d 1176d 14/24 fixed on 2019/10/09 10:54
linux-4.19 BUG: soft lockup in inet_release 1 242d 242d 0/1 auto-closed as invalid on 2022/07/27 00:21

Sample crash report:
rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
rcu: 	0-...!: (1 GPs behind) idle=b11/1/0x4000000000000000 softirq=341015/341020 fqs=0 
rcu: 	Tasks blocked on level-0 rcu_node (CPUs 0-1): P24465/1:b..l
	(detected by 1, t=10502 jiffies, g=324141, q=168)
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 3630 Comm: syz-executor.1 Not tainted 5.17.0-rc2-syzkaller-00316-g0457e5153e0e #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:__kasan_check_read+0x4/0x10 mm/kasan/shadow.c:31
Code: 47 07 48 85 db 0f 85 b7 0d 49 07 48 83 c4 60 5b 5d 41 5c 41 5d c3 c3 e9 b7 0e 49 07 cc cc cc cc cc cc cc cc cc cc 48 8b 0c 24 <89> f6 31 d2 e9 f3 f9 ff ff 0f 1f 00 48 8b 0c 24 89 f6 ba 01 00 00
RSP: 0018:ffffc90000007ad0 EFLAGS: 00000056
RAX: 0000000000000000 RBX: 0000000000000000 RCX: ffffffff815d0955
RDX: 1ffff1100473289a RSI: 0000000000000008 RDI: ffffffff8ffbf940
RBP: 0000000000000000 R08: 0000000000000000 R09: ffffffff8ffbf947
R10: fffffbfff1ff7f28 R11: 0000000000000001 R12: ffff8880239944b0
R13: ffff888023993a00 R14: ffffffff8d93f9e8 R15: 0000000000000000
FS:  0000555556ccc400(0000) GS:ffff8880b9c00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007fe516d47902 CR3: 000000004773c000 CR4: 0000000000350ef0
Call Trace:
 <IRQ>
 instrument_atomic_read include/linux/instrumented.h:71 [inline]
 test_bit include/asm-generic/bitops/instrumented-non-atomic.h:134 [inline]
 hlock_class kernel/locking/lockdep.c:199 [inline]
 lookup_chain_cache_add kernel/locking/lockdep.c:3713 [inline]
 validate_chain kernel/locking/lockdep.c:3769 [inline]
 __lock_acquire+0x1655/0x5470 kernel/locking/lockdep.c:5027
 lock_acquire kernel/locking/lockdep.c:5639 [inline]
 lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5604
 __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
 _raw_spin_lock_irqsave+0x39/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:638
RIP: 0010:refill_obj_stock+0x1bc/0x4a0 mm/memcontrol.c:3238
Code: 00 00 00 00 00 fc ff df 4c 89 fa 48 c1 ea 03 0f b6 04 02 84 c0 74 08 3c 03 0f 8e a4 02 00 00 44 89 63 10 41 81 fc 00 10 00 00 <0f> 86 a4 00 00 00 48 b8 00 00 00 00 00 fc ff df 4c 89 fa 45 89 e5
RSP: 0018:ffffc9000293fc38 EFLAGS: 00000206
RAX: 0000000000000000 RBX: ffff8880b9c35e30 RCX: 1ffffffff20a1b20
RDX: 1ffff11017386bc8 RSI: 0000000000000001 RDI: ffffffff8b58e8a0
RBP: ffff88807ce75780 R08: ffff888140de9000 R09: 0000000000000000
R10: 000000000000000b R11: 000000000000003f R12: 0000000000001690
R13: 0000000000000001 R14: 0000000000000000 R15: ffff8880b9c35e40
 memcg_slab_free_hook mm/slab.h:571 [inline]
 memcg_slab_free_hook+0x17b/0x2e0 mm/slab.h:534
 do_slab_free mm/slub.c:3442 [inline]
 slab_free mm/slub.c:3510 [inline]
 kmem_cache_free+0x2c1/0x340 mm/slub.c:3526
 sk_prot_free net/core/sock.c:1957 [inline]
 __sk_destruct+0x5b6/0x920 net/core/sock.c:2045
 sk_destruct+0x131/0x180 net/core/sock.c:2063
 __sk_free+0xef/0x3d0 net/core/sock.c:2074
 sk_free+0x78/0xa0 net/core/sock.c:2085
 sock_put include/net/sock.h:1912 [inline]
 tcp_close+0x98/0xc0 net/ipv4/tcp.c:2924
 inet_release+0x12e/0x280 net/ipv4/af_inet.c:428
 __sock_release+0xcd/0x280 net/socket.c:650
 sock_close+0x18/0x20 net/socket.c:1318
 __fput+0x286/0x9f0 fs/file_table.c:311
 task_work_run+0xdd/0x1a0 kernel/task_work.c:164
 tracehook_notify_resume include/linux/tracehook.h:188 [inline]
 exit_to_user_mode_loop kernel/entry/common.c:175 [inline]
 exit_to_user_mode_prepare+0x27e/0x290 kernel/entry/common.c:207
 __syscall_exit_to_user_mode_work kernel/entry/common.c:289 [inline]
 syscall_exit_to_user_mode+0x19/0x60 kernel/entry/common.c:300
 do_syscall_64+0x42/0xb0 arch/x86/entry/common.c:86
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x7f4d3ca67c9b
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:00007ffc4c66a570 EFLAGS: 00000293 ORIG_RAX: 0000000000000003
RAX: 0000000000000000 RBX: 00007ffc4c66a610 RCX: 00007f4d3ca67c9b
RDX: 0000000000000040 RSI: 0000000000000000 RDI: 0000000000000003
RBP: 0000000000000003 R08: 0000000000000000 R09: ff78736871746264
R10: 00007f4d3cb9a880 R11: 0000000000000293 R12: 0000000000000032
R13: 00000000001c5043 R14: 0000000000000001 R15: 00007ffc4c66a650
 </TASK>
task:udevd           state:R  running task     stack:25464 pid:24465 ppid:  2961 flags:0x00004000
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4986 [inline]
 __schedule+0xab2/0x4db0 kernel/sched/core.c:6295
 preempt_schedule_common+0x45/0xc0 kernel/sched/core.c:6461
 preempt_schedule_thunk+0x16/0x18 arch/x86/entry/thunk_64.S:35
 vprintk_emit+0x1c9/0x4f0 kernel/printk/printk.c:2246
 vprintk+0x80/0x90 kernel/printk/printk_safe.c:50
 _printk+0xba/0xed kernel/printk/printk.c:2266
 blk_print_req_error block/blk-mq.c:701 [inline]
 blk_update_request+0xbb1/0x1070 block/blk-mq.c:793
 blk_mq_end_request+0x55/0x5f0 block/blk-mq.c:928
 blk_mq_plug_issue_direct.constprop.0+0x20d/0x5a0 block/blk-mq.c:2538
 blk_mq_flush_plug_list+0x713/0xd60 block/blk-mq.c:2596
 blk_flush_plug block/blk-core.c:1282 [inline]
 blk_finish_plug block/blk-core.c:1306 [inline]
 blk_finish_plug+0xb7/0x160 block/blk-core.c:1303
 read_pages+0x737/0xfa0 mm/readahead.c:149
 page_cache_ra_unbounded+0x552/0x740 mm/readahead.c:238
 do_page_cache_ra mm/readahead.c:268 [inline]
 force_page_cache_ra+0x32f/0x4a0 mm/readahead.c:300
 page_cache_sync_ra+0x107/0x200 mm/readahead.c:574
 page_cache_sync_readahead include/linux/pagemap.h:1056 [inline]
 filemap_get_pages+0x2bf/0x16a0 mm/filemap.c:2589
 filemap_read+0x328/0xb90 mm/filemap.c:2676
 blkdev_read_iter+0x3ed/0x760 block/fops.c:614
 call_read_iter include/linux/fs.h:2068 [inline]
 new_sync_read+0x429/0x6e0 fs/read_write.c:400
 vfs_read+0x35c/0x600 fs/read_write.c:481
 ksys_read+0x12d/0x250 fs/read_write.c:619
 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:0x7fe8940b58fe
RSP: 002b:00007ffc7a2f6798 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
RAX: ffffffffffffffda RBX: 00000000080f0000 RCX: 00007fe8940b58fe
RDX: 0000000000000040 RSI: 00007fe895ec3668 RDI: 0000000000000009
RBP: 0000000000000040 R08: 00007fe895ec3640 R09: 00007fe895eb1010
R10: 00007fe894185a00 R11: 0000000000000246 R12: 00007fe895ec3640
R13: 00007fe895ec3658 R14: 00007fe895ec58c0 R15: 00007fe895ec5870
 </TASK>
rcu: rcu_preempt kthread timer wakeup didn't happen for 10501 jiffies! g324141 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402
rcu: 	Possible timer handling issue on cpu=1 timer-softirq=120116
rcu: rcu_preempt kthread starved for 10502 jiffies! g324141 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:28736 pid:   14 ppid:     2 flags:0x00004000
Call Trace:
 <TASK>
 context_switch kernel/sched/core.c:4986 [inline]
 __schedule+0xab2/0x4db0 kernel/sched/core.c:6295
 schedule+0xd2/0x260 kernel/sched/core.c:6368
 schedule_timeout+0x14a/0x2a0 kernel/time/timer.c:1881
 rcu_gp_fqs_loop+0x186/0x810 kernel/rcu/tree.c:1963
 rcu_gp_kthread+0x1de/0x320 kernel/rcu/tree.c:2136
 kthread+0x2e9/0x3a0 kernel/kthread.c:377
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
 </TASK>
rcu: Stack dump where RCU GP kthread last ran:
NMI backtrace for cpu 1
CPU: 1 PID: 32662 Comm: kworker/u4:10 Not tainted 5.17.0-rc2-syzkaller-00316-g0457e5153e0e #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Workqueue: events_unbound toggle_allocation_gate
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+0x1b3/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:458
 print_other_cpu_stall kernel/rcu/tree_stall.h:563 [inline]
 check_cpu_stall kernel/rcu/tree_stall.h:706 [inline]
 rcu_pending kernel/rcu/tree.c:3919 [inline]
 rcu_sched_clock_irq+0x1f7c/0x2150 kernel/rcu/tree.c:2617
 update_process_times+0x16d/0x200 kernel/time/timer.c:1785
 tick_sched_handle+0x9b/0x180 kernel/time/tick-sched.c:226
 tick_sched_timer+0x1b0/0x2d0 kernel/time/tick-sched.c:1428
 __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:638
RIP: 0010:csd_lock_wait kernel/smp.c:440 [inline]
RIP: 0010:smp_call_function_many_cond+0x447/0xc90 kernel/smp.c:969
Code: 0b 00 85 ed 74 4d 48 b8 00 00 00 00 00 fc ff df 4d 89 f4 4c 89 f5 49 c1 ec 03 83 e5 07 49 01 c4 83 c5 03 e8 8b 87 0b 00 f3 90 <41> 0f b6 04 24 40 38 c5 7c 08 84 c0 0f 85 95 06 00 00 8b 43 08 31
RSP: 0018:ffffc90004537a08 EFLAGS: 00000293
RAX: 0000000000000000 RBX: ffff8880b9c41fa0 RCX: 0000000000000000
RDX: ffff88801b075700 RSI: ffffffff816cf105 RDI: 0000000000000003
RBP: 0000000000000003 R08: 0000000000000000 R09: 0000000000000001
R10: ffffffff816cf12b R11: 0000000000000000 R12: ffffed10173883f5
R13: 0000000000000000 R14: ffff8880b9c41fa8 R15: 0000000000000001
 on_each_cpu_cond_mask+0x56/0xa0 kernel/smp.c:1135
 on_each_cpu include/linux/smp.h:71 [inline]
 text_poke_sync arch/x86/kernel/alternative.c:1112 [inline]
 text_poke_bp_batch+0x1b1/0x510 arch/x86/kernel/alternative.c:1300
 text_poke_flush arch/x86/kernel/alternative.c:1470 [inline]
 text_poke_flush arch/x86/kernel/alternative.c:1467 [inline]
 text_poke_finish+0x16/0x30 arch/x86/kernel/alternative.c:1477
 arch_jump_label_transform_apply+0x13/0x20 arch/x86/kernel/jump_label.c:146
 jump_label_update+0x1da/0x400 kernel/jump_label.c:830
 static_key_enable_cpuslocked+0x1b1/0x260 kernel/jump_label.c:177
 static_key_enable+0x16/0x20 kernel/jump_label.c:190
 toggle_allocation_gate mm/kfence/core.c:734 [inline]
 toggle_allocation_gate+0x100/0x390 mm/kfence/core.c:726
 process_one_work+0x9ac/0x1650 kernel/workqueue.c:2307
 worker_thread+0x657/0x1110 kernel/workqueue.c:2454
 kthread+0x2e9/0x3a0 kernel/kthread.c:377
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
 </TASK>
----------------
Code disassembly (best guess):
   0:	47 07                	rex.RXB (bad)
   2:	48 85 db             	test   %rbx,%rbx
   5:	0f 85 b7 0d 49 07    	jne    0x7490dc2
   b:	48 83 c4 60          	add    $0x60,%rsp
   f:	5b                   	pop    %rbx
  10:	5d                   	pop    %rbp
  11:	41 5c                	pop    %r12
  13:	41 5d                	pop    %r13
  15:	c3                   	retq
  16:	c3                   	retq
  17:	e9 b7 0e 49 07       	jmpq   0x7490ed3
  1c:	cc                   	int3
  1d:	cc                   	int3
  1e:	cc                   	int3
  1f:	cc                   	int3
  20:	cc                   	int3
  21:	cc                   	int3
  22:	cc                   	int3
  23:	cc                   	int3
  24:	cc                   	int3
  25:	cc                   	int3
  26:	48 8b 0c 24          	mov    (%rsp),%rcx
* 2a:	89 f6                	mov    %esi,%esi <-- trapping instruction
  2c:	31 d2                	xor    %edx,%edx
  2e:	e9 f3 f9 ff ff       	jmpq   0xfffffa26
  33:	0f 1f 00             	nopl   (%rax)
  36:	48 8b 0c 24          	mov    (%rsp),%rcx
  3a:	89 f6                	mov    %esi,%esi
  3c:	ba                   	.byte 0xba
  3d:	01 00                	add    %eax,(%rax)

Crashes (1):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci-upstream-kasan-gce-root 2022/02/05 18:27 upstream 0457e5153e0e a7dab638 .config log report info INFO: rcu detected stall in inet_release
* Struck through repros no longer work on HEAD.