syzbot


INFO: rcu detected stall in sys_fchown

Status: auto-closed as invalid on 2019/10/25 08:46
Reported-by: syzbot+a0f9d87fb047d09ce05f@syzkaller.appspotmail.com
First crash: 1823d, last: 1823d

Sample crash report:
rcu: INFO: rcu_sched detected stalls on CPUs/tasks:
rcu: 	(detected by 0, t=10502 jiffies, g=10333, q=1)
rcu: All QSes seen, last rcu_sched kthread activity 10496 (4295012650-4295002154), jiffies_till_next_fqs=1, root ->qsmask 0x0
syz-executor.2  R  running task    28336 29841   7592 0x00000000
Call Trace:
 <IRQ>
 sched_show_task kernel/sched/core.c:5297 [inline]
 sched_show_task.cold+0x292/0x30b kernel/sched/core.c:5272
 print_other_cpu_stall kernel/rcu/tree.c:1430 [inline]
 check_cpu_stall kernel/rcu/tree.c:1557 [inline]
 __rcu_pending kernel/rcu/tree.c:3293 [inline]
 rcu_pending kernel/rcu/tree.c:3336 [inline]
 rcu_check_callbacks.cold+0xaa1/0xd93 kernel/rcu/tree.c:2682
 update_process_times+0x32/0x80 kernel/time/timer.c:1636
 tick_sched_handle+0xa2/0x190 kernel/time/tick-sched.c:164
 tick_sched_timer+0x47/0x130 kernel/time/tick-sched.c:1274
 __run_hrtimer kernel/time/hrtimer.c:1398 [inline]
 __hrtimer_run_queues+0x33e/0xde0 kernel/time/hrtimer.c:1460
 hrtimer_interrupt+0x314/0x770 kernel/time/hrtimer.c:1518
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1029 [inline]
 smp_apic_timer_interrupt+0x120/0x570 arch/x86/kernel/apic/apic.c:1054
 apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:867
 </IRQ>
RIP: 0010:arch_local_irq_restore arch/x86/include/asm/paravirt.h:788 [inline]
RIP: 0010:lock_is_held_type+0x17e/0x210 kernel/locking/lockdep.c:3940
Code: 00 00 00 fc ff df 41 c7 85 7c 08 00 00 00 00 00 00 48 c1 e8 03 80 3c 10 00 75 63 48 83 3d c1 59 20 07 00 74 30 48 89 df 57 9d <0f> 1f 44 00 00 48 83 c4 08 44 89 e0 5b 41 5c 41 5d 5d c3 48 83 c4
RSP: 0018:ffff888218c9fdf8 EFLAGS: 00000286 ORIG_RAX: ffffffffffffff13
RAX: 1ffffffff10e4669 RBX: 0000000000000286 RCX: ffff88809f7a2b00
RDX: dffffc0000000000 RSI: ffffffff8879d5a0 RDI: 0000000000000286
RBP: ffff888218c9fe18 R08: ffff88809f7a2280 R09: ffffed1015d04733
R10: ffffed1015d04732 R11: ffff8880ae823993 R12: 0000000000000000
R13: ffff88809f7a2280 R14: 0000000000000108 R15: 000000000918380a
 lock_is_held include/linux/lockdep.h:344 [inline]
 rcu_read_lock_sched_held+0x110/0x130 kernel/rcu/update.c:118
 rcu_sync_lockdep_assert+0x73/0xb0 kernel/rcu/sync.c:68
 rcu_sync_is_idle include/linux/rcu_sync.h:56 [inline]
 percpu_down_read_preempt_disable include/linux/percpu-rwsem.h:48 [inline]
 percpu_down_read include/linux/percpu-rwsem.h:59 [inline]
 __sb_start_write+0x252/0x360 fs/super.c:1387
 sb_start_write include/linux/fs.h:1569 [inline]
 mnt_want_write_file+0x68/0x110 fs/namespace.c:418
 ksys_fchown+0x4d/0x170 fs/open.c:699
 __do_sys_fchown fs/open.c:713 [inline]
 __se_sys_fchown fs/open.c:711 [inline]
 __x64_sys_fchown+0x73/0xb0 fs/open.c:711
 do_syscall_64+0x103/0x610 arch/x86/entry/common.c:290
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x2000068b
Code: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 98 a8 4a 2a e9 2c 21 1c 42 0f 05 <bf> 03 00 00 00 c4 a3 7b f0 c5 5c 41 e2 e9 2e 36 3e 46 0f 1a 70 00
RSP: 002b:00007f971f2b1bd8 EFLAGS: 00000a02 ORIG_RAX: 000000000000005d
RAX: ffffffffffffffda RBX: 0000000000000009 RCX: 000000002000068b
RDX: dd25a2c50918380a RSI: 0000000000000000 RDI: 0000000000000003
RBP: 0000000000000082 R08: 0000000000000005 R09: 0000000000000006
R10: 0000000000000007 R11: 0000000000000a02 R12: 000000000000000b
R13: 000000000000000c R14: 000000000000000d R15: 00000000ffffffff
rcu: rcu_sched kthread starved for 10496 jiffies! g10333 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=1
rcu: RCU grace-period kthread stack dump:
rcu_sched       R  running task    29104    11      2 0x80000000
Call Trace:
 context_switch kernel/sched/core.c:2826 [inline]
 __schedule+0x813/0x1d00 kernel/sched/core.c:3474
 schedule+0x92/0x1c0 kernel/sched/core.c:3518
 schedule_timeout+0x4db/0xfd0 kernel/time/timer.c:1804
 rcu_gp_kthread+0xd5c/0x2190 kernel/rcu/tree.c:2202
 kthread+0x357/0x430 kernel/kthread.c:246
 ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:413
rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
rcu: 	(detected by 0, t=10540 jiffies, g=71877, q=160)
rcu: All QSes seen, last rcu_preempt kthread activity 10538 (4295012692-4295002154), jiffies_till_next_fqs=1, root ->qsmask 0x0
syz-executor.2  R  running task    28336 29841   7592 0x80000000
Call Trace:
 <IRQ>
 sched_show_task kernel/sched/core.c:5297 [inline]
 sched_show_task.cold+0x292/0x30b kernel/sched/core.c:5272
 print_other_cpu_stall kernel/rcu/tree.c:1430 [inline]
 check_cpu_stall kernel/rcu/tree.c:1557 [inline]
 __rcu_pending kernel/rcu/tree.c:3293 [inline]
 rcu_pending kernel/rcu/tree.c:3336 [inline]
 rcu_check_callbacks.cold+0xaa1/0xd93 kernel/rcu/tree.c:2682
 update_process_times+0x32/0x80 kernel/time/timer.c:1636
 tick_sched_handle+0xa2/0x190 kernel/time/tick-sched.c:164
 tick_sched_timer+0x47/0x130 kernel/time/tick-sched.c:1274
 __run_hrtimer kernel/time/hrtimer.c:1398 [inline]
 __hrtimer_run_queues+0x33e/0xde0 kernel/time/hrtimer.c:1460
 hrtimer_interrupt+0x314/0x770 kernel/time/hrtimer.c:1518
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1029 [inline]
 smp_apic_timer_interrupt+0x120/0x570 arch/x86/kernel/apic/apic.c:1054
 apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:867
 </IRQ>
RIP: 0010:arch_local_irq_restore arch/x86/include/asm/paravirt.h:788 [inline]
RIP: 0010:lock_is_held_type+0x17e/0x210 kernel/locking/lockdep.c:3940
Code: 00 00 00 fc ff df 41 c7 85 7c 08 00 00 00 00 00 00 48 c1 e8 03 80 3c 10 00 75 63 48 83 3d c1 59 20 07 00 74 30 48 89 df 57 9d <0f> 1f 44 00 00 48 83 c4 08 44 89 e0 5b 41 5c 41 5d 5d c3 48 83 c4
RSP: 0018:ffff888218c9fdf8 EFLAGS: 00000286 ORIG_RAX: ffffffffffffff13
RAX: 1ffffffff10e4669 RBX: 0000000000000286 RCX: ffff88809f7a2b00
RDX: dffffc0000000000 RSI: ffffffff8879d5a0 RDI: 0000000000000286
RBP: ffff888218c9fe18 R08: ffff88809f7a2280 R09: ffffed1015d04733
R10: ffffed1015d04732 R11: ffff8880ae823993 R12: 0000000000000000
R13: ffff88809f7a2280 R14: 0000000000000108 R15: 000000000918380a
 lock_is_held include/linux/lockdep.h:344 [inline]
 rcu_read_lock_sched_held+0x110/0x130 kernel/rcu/update.c:118
 rcu_sync_lockdep_assert+0x73/0xb0 kernel/rcu/sync.c:68
 rcu_sync_is_idle include/linux/rcu_sync.h:56 [inline]
 percpu_down_read_preempt_disable include/linux/percpu-rwsem.h:48 [inline]
 percpu_down_read include/linux/percpu-rwsem.h:59 [inline]
 __sb_start_write+0x252/0x360 fs/super.c:1387
 sb_start_write include/linux/fs.h:1569 [inline]
 mnt_want_write_file+0x68/0x110 fs/namespace.c:418
 ksys_fchown+0x4d/0x170 fs/open.c:699
 __do_sys_fchown fs/open.c:713 [inline]
 __se_sys_fchown fs/open.c:711 [inline]
 __x64_sys_fchown+0x73/0xb0 fs/open.c:711
 do_syscall_64+0x103/0x610 arch/x86/entry/common.c:290
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x2000068b
Code: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 98 a8 4a 2a e9 2c 21 1c 42 0f 05 <bf> 03 00 00 00 c4 a3 7b f0 c5 5c 41 e2 e9 2e 36 3e 46 0f 1a 70 00
RSP: 002b:00007f971f2b1bd8 EFLAGS: 00000a02 ORIG_RAX: 000000000000005d
RAX: ffffffffffffffda RBX: 0000000000000009 RCX: 000000002000068b
RDX: dd25a2c50918380a RSI: 0000000000000000 RDI: 0000000000000003
RBP: 0000000000000082 R08: 0000000000000005 R09: 0000000000000006
R10: 0000000000000007 R11: 0000000000000a02 R12: 000000000000000b
R13: 000000000000000c R14: 000000000000000d R15: 00000000ffffffff
rcu: rcu_preempt kthread starved for 10538 jiffies! g71877 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=1
rcu: RCU grace-period kthread stack dump:
rcu_preempt     R  running task    29104    10      2 0x80000000
Call Trace:
 context_switch kernel/sched/core.c:2826 [inline]
 __schedule+0x813/0x1d00 kernel/sched/core.c:3474
 schedule+0x92/0x1c0 kernel/sched/core.c:3518
 schedule_timeout+0x4db/0xfd0 kernel/time/timer.c:1804
 rcu_gp_kthread+0xd5c/0x2190 kernel/rcu/tree.c:2202
 kthread+0x357/0x430 kernel/kthread.c:246
 ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:413
IPVS: ftp: loaded support on port[0] = 21
device bridge_slave_1 left promiscuous mode
bridge0: port 2(bridge_slave_1) entered disabled state
device bridge_slave_0 left promiscuous mode
bridge0: port 1(bridge_slave_0) entered disabled state
device hsr_slave_1 left promiscuous mode
device hsr_slave_0 left promiscuous mode
team0 (unregistering): Port device team_slave_1 removed
team0 (unregistering): Port device team_slave_0 removed
bond0 (unregistering): Releasing backup interface bond_slave_1
bond0 (unregistering): Releasing backup interface bond_slave_0
bond0 (unregistering): Released all slaves
IPVS: ftp: loaded support on port[0] = 21
IPVS: ftp: loaded support on port[0] = 21
IPVS: ftp: loaded support on port[0] = 21
IPVS: ftp: loaded support on port[0] = 21
IPVS: ftp: loaded support on port[0] = 21
chnl_net:caif_netlink_parms(): no params data found
bridge0: port 1(bridge_slave_0) entered blocking state
bridge0: port 1(bridge_slave_0) entered disabled state
device bridge_slave_0 entered promiscuous mode
bridge0: port 2(bridge_slave_1) entered blocking state
bridge0: port 2(bridge_slave_1) entered disabled state
device bridge_slave_1 entered promiscuous mode
bond0: Enslaving bond_slave_0 as an active interface with an up link
bond0: Enslaving bond_slave_1 as an active interface with an up link
chnl_net:caif_netlink_parms(): no params data found
IPv6: ADDRCONF(NETDEV_UP): team_slave_0: link is not ready
team0: Port device team_slave_0 added
IPv6: ADDRCONF(NETDEV_UP): team_slave_1: link is not ready
team0: Port device team_slave_1 added
chnl_net:caif_netlink_parms(): no params data found
chnl_net:caif_netlink_parms(): no params data found
IPv6: ADDRCONF(NETDEV_UP): bridge_slave_0: link is not ready
IPv6: ADDRCONF(NETDEV_UP): bridge_slave_1: link is not ready
chnl_net:caif_netlink_parms(): no params data found
bridge0: port 1(bridge_slave_0) entered blocking state
bridge0: port 1(bridge_slave_0) entered disabled state
device bridge_slave_0 entered promiscuous mode
chnl_net:caif_netlink_parms(): no params data found
device hsr_slave_0 entered promiscuous mode
device hsr_slave_1 entered promiscuous mode

Crashes (1):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2019/04/30 08:35 linux-4.19.y 19bb613acb9a 20f16bef .config console log report ci2-linux-4-19
* Struck through repros no longer work on HEAD.