possible deadlock in flush_work (3)

Status: auto-closed as invalid on 2019/02/22 10:34
Subsystems: net
[Documentation on labels]
Reported-by: syzbot+a8371264572a6872b8a3@syzkaller.appspotmail.com
First crash: 2931d, last: 2927d
▶ ▼ Discussions (1)
Title Replies (including bot) Last reply
possible deadlock in flush_work (3) 1 (2) 2018/08/13 15:39
▶ ▼ Similar bugs (3)
Kernel Title Rank 🛈 Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream possible deadlock in flush_work 4 syz, C 180 3212d 3288d 0/29 closed as invalid on 2017/11/01 20:11
upstream possible deadlock in flush_work (2) nfs net 4 3 3205d 3208d 4/29 fixed on 2018/02/14 17:41
linux-4.14 possible deadlock in flush_work 4 syz, C inconclusive 23 2271d 2684d 0/1 upstream: reported C repro on 2019/04/13 06:23

Sample crash report:
8021q: adding VLAN 0 to HW filter on device bond0

======================================================
WARNING: possible circular locking dependency detected
4.18.0-rc8+ #185 Not tainted
------------------------------------------------------
syz-executor2/6421 is trying to acquire lock:
00000000209b4e4b ((wq_completion)bond_dev->name){+.+.}, at: start_flush_work kernel/workqueue.c:2888 [inline]
00000000209b4e4b ((wq_completion)bond_dev->name){+.+.}, at: flush_work+0x4b8/0x900 kernel/workqueue.c:2917

but task is already holding lock:
00000000f0f3d47a (rtnl_mutex){+.+.}, at: rtnl_lock+0x17/0x20 net/core/rtnetlink.c:77

which lock already depends on the new lock.


the existing dependency chain (in reverse order) is:

-> #2 (rtnl_mutex){+.+.}:
       __mutex_lock_common kernel/locking/mutex.c:757 [inline]
       __mutex_lock+0x176/0x1820 kernel/locking/mutex.c:894
       mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:909
       rtnl_lock+0x17/0x20 net/core/rtnetlink.c:77
       bond_netdev_notify drivers/net/bonding/bond_main.c:1310 [inline]
       bond_netdev_notify_work+0x44/0xd0 drivers/net/bonding/bond_main.c:1320
       process_one_work+0xc73/0x1ba0 kernel/workqueue.c:2153
       worker_thread+0x189/0x13c0 kernel/workqueue.c:2296
       kthread+0x345/0x410 kernel/kthread.c:246
       ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:412

-> #1 ((work_completion)(&(&nnw->work)->work)){+.+.}:
       process_one_work+0xc0b/0x1ba0 kernel/workqueue.c:2129
       worker_thread+0x189/0x13c0 kernel/workqueue.c:2296
       kthread+0x345/0x410 kernel/kthread.c:246
       ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:412

-> #0 ((wq_completion)bond_dev->name){+.+.}:
       lock_acquire+0x1e4/0x540 kernel/locking/lockdep.c:3924
       start_flush_work kernel/workqueue.c:2889 [inline]
       flush_work+0x4dd/0x900 kernel/workqueue.c:2917
       __cancel_work_timer+0x4bd/0x830 kernel/workqueue.c:2989
       cancel_delayed_work_sync+0x1a/0x20 kernel/workqueue.c:3121
       bond_work_cancel_all drivers/net/bonding/bond_main.c:3318 [inline]
       bond_close+0x1b/0x130 drivers/net/bonding/bond_main.c:3381
       __dev_close_many+0x21e/0x380 net/core/dev.c:1476
       __dev_close net/core/dev.c:1488 [inline]
       __dev_change_flags+0x38d/0x9c0 net/core/dev.c:6989
       dev_change_flags+0x89/0x150 net/core/dev.c:7060
       dev_ifsioc+0x84f/0xb30 net/core/dev_ioctl.c:237
       dev_ioctl+0x1b5/0xcc0 net/core/dev_ioctl.c:493
       sock_do_ioctl+0x1d3/0x3e0 net/socket.c:993
       sock_ioctl+0x30d/0x680 net/socket.c:1094
       vfs_ioctl fs/ioctl.c:46 [inline]
       file_ioctl fs/ioctl.c:500 [inline]
       do_vfs_ioctl+0x1de/0x1720 fs/ioctl.c:684
       ksys_ioctl+0xa9/0xd0 fs/ioctl.c:701
       __do_sys_ioctl fs/ioctl.c:708 [inline]
       __se_sys_ioctl fs/ioctl.c:706 [inline]
       __x64_sys_ioctl+0x73/0xb0 fs/ioctl.c:706
       do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
       entry_SYSCALL_64_after_hwframe+0x49/0xbe

other info that might help us debug this:

Chain exists of:
  (wq_completion)bond_dev->name --> (work_completion)(&(&nnw->work)->work) --> rtnl_mutex

 Possible unsafe locking scenario:

       CPU0                    CPU1
       ----                    ----
  lock(rtnl_mutex);
                               lock((work_completion)(&(&nnw->work)->work));
                               lock(rtnl_mutex);
  lock((wq_completion)bond_dev->name);

 *** DEADLOCK ***

1 lock held by syz-executor2/6421:
 #0: 00000000f0f3d47a (rtnl_mutex){+.+.}, at: rtnl_lock+0x17/0x20 net/core/rtnetlink.c:77

stack backtrace:
CPU: 0 PID: 6421 Comm: syz-executor2 Not tainted 4.18.0-rc8+ #185
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 __dump_stack lib/dump_stack.c:77 [inline]
 dump_stack+0x1c9/0x2b4 lib/dump_stack.c:113
 print_circular_bug.isra.36.cold.57+0x1bd/0x27d kernel/locking/lockdep.c:1227
 check_prev_add kernel/locking/lockdep.c:1867 [inline]
 check_prevs_add kernel/locking/lockdep.c:1980 [inline]
 validate_chain kernel/locking/lockdep.c:2421 [inline]
 __lock_acquire+0x3449/0x5020 kernel/locking/lockdep.c:3435
 lock_acquire+0x1e4/0x540 kernel/locking/lockdep.c:3924
 start_flush_work kernel/workqueue.c:2889 [inline]
 flush_work+0x4dd/0x900 kernel/workqueue.c:2917
 __cancel_work_timer+0x4bd/0x830 kernel/workqueue.c:2989
 cancel_delayed_work_sync+0x1a/0x20 kernel/workqueue.c:3121
 bond_work_cancel_all drivers/net/bonding/bond_main.c:3318 [inline]
 bond_close+0x1b/0x130 drivers/net/bonding/bond_main.c:3381
 __dev_close_many+0x21e/0x380 net/core/dev.c:1476
 __dev_close net/core/dev.c:1488 [inline]
 __dev_change_flags+0x38d/0x9c0 net/core/dev.c:6989
 dev_change_flags+0x89/0x150 net/core/dev.c:7060
 dev_ifsioc+0x84f/0xb30 net/core/dev_ioctl.c:237
 dev_ioctl+0x1b5/0xcc0 net/core/dev_ioctl.c:493
 sock_do_ioctl+0x1d3/0x3e0 net/socket.c:993
kernel msg: ebtables bug: please report to author: Wrong nr of counters
 sock_ioctl+0x30d/0x680 net/socket.c:1094
 vfs_ioctl fs/ioctl.c:46 [inline]
 file_ioctl fs/ioctl.c:500 [inline]
 do_vfs_ioctl+0x1de/0x1720 fs/ioctl.c:684
 ksys_ioctl+0xa9/0xd0 fs/ioctl.c:701
 __do_sys_ioctl fs/ioctl.c:708 [inline]
 __se_sys_ioctl fs/ioctl.c:706 [inline]
 __x64_sys_ioctl+0x73/0xb0 fs/ioctl.c:706
 do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x457089
Code: fd b4 fb ff c3 66 2e 0f 1f 84 00 00 00 00 00 66 90 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 cb b4 fb ff c3 66 2e 0f 1f 84 00 00 00 00 
RSP: 002b:00007fee7b2ccc78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00007fee7b2cd6d4 RCX: 0000000000457089
RDX: 0000000020000140 RSI: 0000000000008914 RDI: 0000000000000004
RBP: 00000000009300a0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
R13: 00000000004d19e0 R14: 00000000004c7454 R15: 0000000000000000
8021q: adding VLAN 0 to HW filter on device bond0
(unnamed net_device) (uninitialized): option miimon: invalid value (18446744073709551615)
(unnamed net_device) (uninitialized): option miimon: allowed values 0 - 2147483647
(unnamed net_device) (uninitialized): option miimon: invalid value (18446744073709551615)
(unnamed net_device) (uninitialized): option miimon: allowed values 0 - 2147483647
8021q: adding VLAN 0 to HW filter on device bond0
8021q: adding VLAN 0 to HW filter on device bond0
8021q: adding VLAN 0 to HW filter on device bond0
8021q: adding VLAN 0 to HW filter on device bond0
8021q: adding VLAN 0 to HW filter on device bond0
8021q: adding VLAN 0 to HW filter on device bond0
8021q: adding VLAN 0 to HW filter on device bond0
8021q: adding VLAN 0 to HW filter on device bond0
8021q: adding VLAN 0 to HW filter on device bond0
8021q: adding VLAN 0 to HW filter on device bond0
8021q: adding VLAN 0 to HW filter on device bond0
8021q: adding VLAN 0 to HW filter on device bond0
8021q: adding VLAN 0 to HW filter on device bond0
device bond0 left promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): bond0: link is not ready
8021q: adding VLAN 0 to HW filter on device bond0
8021q: adding VLAN 0 to HW filter on device bond0
8021q: adding VLAN 0 to HW filter on device bond0
IPv6: ADDRCONF(NETDEV_UP): bond0: link is not ready
8021q: adding VLAN 0 to HW filter on device bond0
8021q: adding VLAN 0 to HW filter on device bond0
8021q: adding VLAN 0 to HW filter on device bond0
IPv6: ADDRCONF(NETDEV_UP): bond0: link is not ready
8021q: adding VLAN 0 to HW filter on device bond0
8021q: adding VLAN 0 to HW filter on device bond0
8021q: adding VLAN 0 to HW filter on device bond0
8021q: adding VLAN 0 to HW filter on device bond0
8021q: adding VLAN 0 to HW filter on device bond0
8021q: adding VLAN 0 to HW filter on device bond0
8021q: adding VLAN 0 to HW filter on device bond0
8021q: adding VLAN 0 to HW filter on device bond0

Crashes (3):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2018/08/13 07:40 upstream d6dd6431591b 7a88b141 .config console log report ci-upstream-kasan-gce
2018/08/11 22:45 net-old d472b3a6cf63 7a88b141 .config console log report ci-upstream-net-this-kasan-gce
2018/08/09 02:25 net-old b13f9c636437 2eeda842 .config console log report ci-upstream-net-this-kasan-gce
* Struck through repros no longer work on HEAD.