Messages in this thread | | | Date | Mon, 1 Nov 2021 22:52:19 +0200 | From | Ido Schimmel <> | Subject | Re: [PATCH net-next] devlink: Require devlink lock during device reload |
| |
On Mon, Nov 01, 2021 at 04:03:05PM +0100, Jiri Pirko wrote: > Sun, Oct 31, 2021 at 06:35:56PM CET, leon@kernel.org wrote: > >From: Leon Romanovsky <leonro@nvidia.com> > > > >Devlink reload was implemented as a special command which does _SET_ > >operation, but doesn't take devlink->lock, while recursive devlink > >calls that were part of .reload_up()/.reload_down() sequence took it. > > > >This fragile flow was possible due to holding a big devlink lock > >(devlink_mutex), which effectively stopped all devlink activities, > >even unrelated to reloaded devlink. > > > >So let's make sure that devlink reload behaves as other commands and > >use special nested locking primitives with a depth of 1. Such change > >opens us to a venue of removing devlink_mutex completely, while keeping > >devlink locking complexity in devlink.c. > > > >Signed-off-by: Leon Romanovsky <leonro@nvidia.com> > > Looks fine to me. > > Reviewed-by: Jiri Pirko <jiri@nvidia.com>
Traces from mlxsw / netdevsim below:
INFO: task syz-executor.0:569 blocked for more than 143 seconds. Not tainted 5.15.0-rc7-custom-64786-g16ed1b4acff7 #1 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. task:syz-executor.0 state:D stack:24856 pid: 569 ppid: 1 flags:0x00004004 Call Trace: context_switch kernel/sched/core.c:4940 [inline] __schedule+0x9da/0x22f0 kernel/sched/core.c:6287 schedule+0xe5/0x280 kernel/sched/core.c:6366 schedule_preempt_disabled+0x18/0x30 kernel/sched/core.c:6425 __mutex_lock_common kernel/locking/mutex.c:669 [inline] __mutex_lock+0xc06/0x1630 kernel/locking/mutex.c:729 mutex_lock_nested+0x1b/0x20 kernel/locking/mutex.c:743 devlink_port_unregister+0x6a/0x260 net/core/devlink.c:9255 __mlxsw_core_port_fini+0x4c/0x70 drivers/net/ethernet/mellanox/mlxsw/core.c:2787 mlxsw_core_port_fini+0x3c/0x50 drivers/net/ethernet/mellanox/mlxsw/core.c:2817 mlxsw_sp_port_remove+0x3a2/0x500 drivers/net/ethernet/mellanox/mlxsw/spectrum.c:1807 mlxsw_sp_ports_remove drivers/net/ethernet/mellanox/mlxsw/spectrum.c:1870 [inline] mlxsw_sp_fini+0xec/0x500 drivers/net/ethernet/mellanox/mlxsw/spectrum.c:3095 mlxsw_core_bus_device_unregister+0xdf/0x6c0 drivers/net/ethernet/mellanox/mlxsw/core.c:2091 mlxsw_devlink_core_bus_device_reload_down+0x87/0xb0 drivers/net/ethernet/mellanox/mlxsw/core.c:1473 devlink_reload+0x184/0x630 net/core/devlink.c:4040 devlink_nl_cmd_reload+0x612/0x1320 net/core/devlink.c:4161 genl_family_rcv_msg_doit.isra.0+0x253/0x370 net/netlink/genetlink.c:731 genl_family_rcv_msg net/netlink/genetlink.c:775 [inline] genl_rcv_msg+0x389/0x620 net/netlink/genetlink.c:792 netlink_rcv_skb+0x173/0x480 net/netlink/af_netlink.c:2491 genl_rcv+0x2e/0x40 net/netlink/genetlink.c:803 netlink_unicast_kernel net/netlink/af_netlink.c:1319 [inline] netlink_unicast+0x5ae/0x7f0 net/netlink/af_netlink.c:1345 netlink_sendmsg+0x8e1/0xe30 net/netlink/af_netlink.c:1916 sock_sendmsg_nosec net/socket.c:704 [inline] sock_sendmsg net/socket.c:724 [inline] __sys_sendto+0x2b6/0x410 net/socket.c:2036 __do_sys_sendto net/socket.c:2048 [inline] __se_sys_sendto net/socket.c:2044 [inline] __x64_sys_sendto+0xe6/0x1a0 net/socket.c:2044 do_syscall_x64 arch/x86/entry/common.c:50 [inline] do_syscall_64+0x35/0x80 arch/x86/entry/common.c:80 entry_SYSCALL_64_after_hwframe+0x44/0xae RIP: 0033:0x41f91a RSP: 002b:00007fffc5b2f5b8 EFLAGS: 00000246 ORIG_RAX: 000000000000002c RAX: ffffffffffffffda RBX: 00000000014c4320 RCX: 000000000041f91a RDX: 0000000000000038 RSI: 00000000014c4370 RDI: 0000000000000004 RBP: 0000000000000001 R08: 00007fffc5b2f5d4 R09: 000000000000000c R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000 R13: 00000000014c4370 R14: 0000000000000004 R15: 0000000000000000
Showing all locks held in the system: 3 locks held by kworker/1:0/20: #0: ffff88811aff0558 (&rq->__lock){-.-.}-{2:2}, at: raw_spin_rq_lock_nested+0x28/0x40 kernel/sched/core.c:474 #1: ffffffff85ae9c20 (rcu_read_lock){....}-{1:2}, at: trace_sched_stat_runtime include/trace/events/sched.h:517 [inline] #1: ffffffff85ae9c20 (rcu_read_lock){....}-{1:2}, at: update_curr+0x1e3/0x7c0 kernel/sched/fair.c:852 #2: ffff88811afdfcc0 (krc.lock){..-.}-{2:2}, at: kfree_rcu_work+0x549/0x10e0 kernel/rcu/tree.c:3288 1 lock held by khungtaskd/26: #0: ffffffff85ae9c20 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x5f/0x27f kernel/locking/lockdep.c:6448 1 lock held by systemd-journal/95: 1 lock held by in:imklog/410: #0: ffff88810da2cbc0 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0xff/0x120 fs/file.c:990 4 locks held by rs:main Q:Reg/411: 5 locks held by syz-executor.0/569: #0: ffffffff862f26b8 (cb_lock){++++}-{3:3}, at: genl_rcv+0x1f/0x40 net/netlink/genetlink.c:802 #1: ffffffff862f2790 (genl_mutex){+.+.}-{3:3}, at: genl_lock net/netlink/genetlink.c:33 [inline] #1: ffffffff862f2790 (genl_mutex){+.+.}-{3:3}, at: genl_rcv_msg+0x43d/0x620 net/netlink/genetlink.c:790 #2: ffffffff862cec70 (devlink_mutex){+.+.}-{3:3}, at: devlink_nl_pre_doit+0x34/0xa10 net/core/devlink.c:575 #3: ffff88810344c278 (&devlink->lock#2){+.+.}-{3:3}, at: devlink_nl_pre_doit+0x4ae/0xa10 net/core/devlink.c:582 #4: ffff88810344c278 (&devlink->lock/1){+.+.}-{3:3}, at: devlink_port_unregister+0x6a/0x260 net/core/devlink.c:9255
INFO: task devlink:1172 blocked for more than 143 seconds. Not tainted 5.15.0-rc7-custom-64786-g16ed1b4acff7 #536 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. task:devlink state:D stack:25736 pid: 1172 ppid: 977 flags:0x00004000 Call Trace: __schedule+0xa14/0x2660 schedule+0xd8/0x270 schedule_preempt_disabled+0x14/0x20 __mutex_lock+0xa1f/0x1320 devlink_port_unregister+0xd2/0x2d0 __nsim_dev_port_del+0x1c8/0x250 [netdevsim] nsim_dev_reload_destroy+0x1a3/0x2f0 [netdevsim] nsim_dev_reload_down+0x105/0x1a0 [netdevsim] devlink_reload+0x52a/0x6a0 devlink_nl_cmd_reload+0x71d/0x1210 genl_family_rcv_msg_doit+0x22a/0x320 genl_rcv_msg+0x341/0x5a0 netlink_rcv_skb+0x14d/0x430 genl_rcv+0x29/0x40 netlink_unicast+0x539/0x7e0 netlink_sendmsg+0x84d/0xd80 __sys_sendto+0x23f/0x350 __x64_sys_sendto+0xe2/0x1b0 do_syscall_64+0x35/0x80 entry_SYSCALL_64_after_hwframe+0x44/0xae RIP: 0033:0x7fd4f9d0314a RSP: 002b:00007fff18371848 EFLAGS: 00000246 ORIG_RAX: 000000000000002c RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00007fd4f9d0314a RDX: 0000000000000034 RSI: 00000000006f0ad0 RDI: 0000000000000003 RBP: 00000000006f0aa0 R08: 00007fd4f9dd9200 R09: 000000000000000c R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000408d80 R13: 00000000006f0910 R14: 0000000000000000 R15: 0000000000000001 Showing all locks held in the system: 1 lock held by khungtaskd/62: #0: ffffffff83ca4aa0 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x28c 3 locks held by kworker/4:2/144: #0: ffff888100101548 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x8ac/0x16f0 #1: ffffc9000209fdb0 ((work_completion)(&(&nsim_dev->trap_data->trap_report_dw)->work)){+.+.}-{0:0}, at: process_one_work+0x8e0/0x16f0 #2: ffff888123f9d440 (&nsim_dev->port_list_lock){+.+.}-{3:3}, at: nsim_dev_trap_report_work+0x62/0xbc0 [netdevsim] 1 lock held by dmesg/1045: 7 locks held by devlink/1172: #0: ffffffff8423dbd8 (cb_lock){++++}-{3:3}, at: genl_rcv+0x1a/0x40 #1: ffffffff8423dcb0 (genl_mutex){+.+.}-{3:3}, at: genl_rcv_msg+0x3f9/0x5a0 #2: ffffffff84222050 (devlink_mutex){+.+.}-{3:3}, at: devlink_nl_pre_doit+0x30/0xa20 #3: ffff888123f9d278 (&devlink->lock#2){+.+.}-{3:3}, at: devlink_nl_pre_doit+0x376/0xa20 #4: ffff888176758d10 (&nsim_bus_dev->nsim_bus_reload_lock){+.+.}-{3:3}, at: nsim_dev_reload_down+0x52/0x1a0 [netdevsim] #5: ffff888123f9d440 (&nsim_dev->port_list_lock){+.+.}-{3:3}, at: nsim_dev_reload_destroy+0x142/0x2f0 [netdevsim] #6: ffff888123f9d278 (&devlink->lock/1){+.+.}-{3:3}, at: devlink_port_unregister+0xd2/0x2d0
| |