syzbot


INFO: rcu detected stall in sys_sendmsg

Status: fixed on 2019/10/09 10:54
Subsystems: net
[Documentation on labels]
Fix commit: d4d6ec6dac07 sch_hhf: ensure quantum and hhf_non_hh_weight are non-zero
First crash: 1679d, last: 1678d
Cause bisection: the issue happens on the oldest tested release (bisect log)
Crash: BUG: soft lockup in netlink_sendmsg (log)
Repro: C syz .config
  
Similar bugs (3)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: rcu detected stall in sys_sendmsg (2) cgroups mm 5 1597d 1599d 0/26 closed as invalid on 2019/12/04 14:14
upstream INFO: rcu detected stall in sys_sendmsg (3) kernel 1 1562d 1562d 0/26 closed as invalid on 2020/01/08 05:33
linux-5.15 INFO: rcu detected stall in sys_sendmsg C 3 1d14h 30d 0/3 upstream: reported C repro on 2024/03/19 21:37

Sample crash report:
rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
	(detected by 1, t=10502 jiffies, g=7585, q=246)
rcu: All QSes seen, last rcu_preempt kthread activity 10503 (4294970158-4294959655), jiffies_till_next_fqs=1, root ->qsmask 0x0
syz-executor781 R  running task    28792  9373   9354 0x0000000a
Call Trace:
 <IRQ>
 sched_show_task+0x348/0x400 kernel/sched/core.c:5758
 print_other_cpu_stall kernel/rcu/tree_stall.h:410 [inline]
 check_cpu_stall kernel/rcu/tree_stall.h:536 [inline]
 rcu_pending kernel/rcu/tree.c:2736 [inline]
 rcu_sched_clock_irq+0x1597/0x16d0 kernel/rcu/tree.c:2183
 update_process_times+0x134/0x190 kernel/time/timer.c:1639
 tick_sched_handle kernel/time/tick-sched.c:167 [inline]
 tick_sched_timer+0x263/0x420 kernel/time/tick-sched.c:1296
 __run_hrtimer kernel/time/hrtimer.c:1389 [inline]
 __hrtimer_run_queues+0x403/0x850 kernel/time/hrtimer.c:1451
 hrtimer_interrupt+0x38c/0xda0 kernel/time/hrtimer.c:1509
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1110 [inline]
 smp_apic_timer_interrupt+0x109/0x280 arch/x86/kernel/apic/apic.c:1135
 apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:830
 </IRQ>
RIP: 0010:atomic_read include/asm-generic/atomic-instrumented.h:26 [inline]
RIP: 0010:virt_spin_lock arch/x86/include/asm/qspinlock.h:83 [inline]
RIP: 0010:native_queued_spin_lock_slowpath+0x92/0x9e0 kernel/locking/qspinlock.c:325
Code: 84 c0 74 54 44 89 f9 80 e1 07 80 c1 03 38 c1 7c 47 4c 89 ff e8 4f f4 51 00 eb 3d 0f 1f 00 66 2e 0f 1f 84 00 00 00 00 00 f3 90 <4c> 89 ff be 04 00 00 00 e8 61 c5 51 00 42 0f b6 04 2b 84 c0 74 18
RSP: 0018:ffff88809312f4f0 EFLAGS: 00000202 ORIG_RAX: ffffffffffffff13
RAX: 0000000000000000 RBX: 1ffff110140d52f5 RCX: ffffffff815a940f
RDX: 0000000000000000 RSI: 0000000000000004 RDI: ffff8880a06a97a8
RBP: ffff88809312f568 R08: dffffc0000000000 R09: ffffed10140d52f6
R10: ffffed10140d52f6 R11: 0000000000000000 R12: ffff8880a06a97b0
R13: dffffc0000000000 R14: 0000000000000001 R15: ffff8880a06a97a8
 pv_queued_spin_lock_slowpath arch/x86/include/asm/paravirt.h:654 [inline]
 queued_spin_lock_slowpath arch/x86/include/asm/qspinlock.h:50 [inline]
 queued_spin_lock include/asm-generic/qspinlock.h:81 [inline]
 do_raw_spin_lock+0x1d6/0x2d0 kernel/locking/spinlock_debug.c:113
 __raw_spin_lock_bh include/linux/spinlock_api_smp.h:136 [inline]
 _raw_spin_lock_bh+0x40/0x50 kernel/locking/spinlock.c:175
 spin_lock_bh include/linux/spinlock.h:343 [inline]
 sch_tree_lock include/net/sch_generic.h:570 [inline]
 hhf_change+0x250/0x9b0 net/sched/sch_hhf.c:537
 qdisc_change net/sched/sch_api.c:1321 [inline]
 tc_modify_qdisc+0x184d/0x1ea0 net/sched/sch_api.c:1623
 rtnetlink_rcv_msg+0x889/0xd40 net/core/rtnetlink.c:5223
 netlink_rcv_skb+0x19e/0x3d0 net/netlink/af_netlink.c:2477
 rtnetlink_rcv+0x1c/0x20 net/core/rtnetlink.c:5241
 netlink_unicast_kernel net/netlink/af_netlink.c:1302 [inline]
 netlink_unicast+0x787/0x900 net/netlink/af_netlink.c:1328
 netlink_sendmsg+0x993/0xc50 net/netlink/af_netlink.c:1917
 sock_sendmsg_nosec net/socket.c:637 [inline]
 sock_sendmsg net/socket.c:657 [inline]
 ___sys_sendmsg+0x60d/0x910 net/socket.c:2311
 __sys_sendmsg net/socket.c:2356 [inline]
 __do_sys_sendmsg net/socket.c:2365 [inline]
 __se_sys_sendmsg net/socket.c:2363 [inline]
 __x64_sys_sendmsg+0x17c/0x200 net/socket.c:2363
 do_syscall_64+0xfe/0x140 arch/x86/entry/common.c:296
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x442399
Code: e8 9c 07 03 00 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 3b 0a fc ff c3 66 2e 0f 1f 84 00 00 00 00
RSP: 002b:00007ffe98336468 EFLAGS: 00000246 ORIG_RAX: 000000000000002e
RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 0000000000442399
RDX: 0000000000000000 RSI: 0000000020000240 RDI: 0000000000000003
RBP: 0000000000037053 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00000000004032f0 R14: 0000000000000000 R15: 0000000000000000
rcu: rcu_preempt kthread starved for 10545 jiffies! g7585 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=0
rcu: RCU grace-period kthread stack dump:
rcu_preempt     R  running task    29080    10      2 0x80004000
Call Trace:
 context_switch kernel/sched/core.c:3254 [inline]
 __schedule+0x877/0xc50 kernel/sched/core.c:3880
 schedule+0x131/0x1e0 kernel/sched/core.c:3947
 schedule_timeout+0x14f/0x240 kernel/time/timer.c:1807
 rcu_gp_fqs_loop kernel/rcu/tree.c:1611 [inline]
 rcu_gp_kthread+0xef8/0x1790 kernel/rcu/tree.c:1768
 kthread+0x332/0x350 kernel/kthread.c:255
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:352

Crashes (2):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2019/09/14 06:13 upstream a7f89616b737 32d59357 .config console log report syz C ci-upstream-kasan-gce-smack-root
2019/09/13 23:11 upstream a7f89616b737 32d59357 .config console log report syz C ci-upstream-kasan-gce-smack-root
* Struck through repros no longer work on HEAD.