2022-02-02 13:50:55

by Toke Høiland-Jørgensen

[permalink] [raw]
Subject: Another hang in cfg80211_destroy_iface_wk()

Hi Johannes

I'm running into a deadlock on my laptop that on the face of it seems to
be similar to the one you fixed back in April in
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=ea6b2098dd02789f68770fd3d5a373732207be2f

Only this happens on my pristine 5.16.3-arch1-1 kernel. It does involve
iwd, though; looks like iwd is crashing, which I guess causes the
interface to get torn down, causing the hang?

I left 'dmesg -w' running while this happened, and got the splats below
more or less simultaneously - any clue what might be going on here?

-Toke

[54189.370954] INFO: task kworker/4:2:131133 blocked for more than 122 seconds.
[54189.370966] Tainted: G U OE 5.16.3-arch1-1 #1
[54189.370971] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[54189.370974] task:kworker/4:2 state:D stack: 0 pid:131133 ppid: 2 flags:0x00004000
[54189.370987] Workqueue: events cfg80211_destroy_iface_wk [cfg80211]
[54189.371089] Call Trace:
[54189.371092] <TASK>
[54189.371100] __schedule+0x307/0x10d0
[54189.371116] ? preempt_schedule_thunk+0x16/0x18
[54189.371129] schedule+0x4b/0xd0
[54189.371136] schedule_preempt_disabled+0x11/0x20
[54189.371143] __mutex_lock.constprop.0+0x256/0x450
[54189.371160] cfg80211_netdev_notifier_call+0x13a/0x500 [cfg80211 a54daa6064550d2f8e9fbeda732654ff2f76efba]
[54189.371252] raw_notifier_call_chain+0x44/0x60
[54189.371261] __dev_close_many+0x70/0x130
[54189.371270] dev_close_many+0x9c/0x150
[54189.371277] unregister_netdevice_many+0x16a/0x760
[54189.371288] unregister_netdevice_queue+0xe4/0x120
[54189.371297] _cfg80211_unregister_wdev+0x14a/0x1e0 [cfg80211 a54daa6064550d2f8e9fbeda732654ff2f76efba]
[54189.371374] ieee80211_if_remove+0x92/0x120 [mac80211 8b88b4a7d6e6c9d99095e6aeff6275c4c2fc1d1d]
[54189.371496] ieee80211_del_iface+0xe/0x20 [mac80211 8b88b4a7d6e6c9d99095e6aeff6275c4c2fc1d1d]
[54189.371601] cfg80211_destroy_ifaces+0xf4/0x1f0 [cfg80211 a54daa6064550d2f8e9fbeda732654ff2f76efba]
[54189.371683] cfg80211_destroy_iface_wk+0x1a/0x20 [cfg80211 a54daa6064550d2f8e9fbeda732654ff2f76efba]
[54189.371757] process_one_work+0x1e8/0x3c0
[54189.371766] worker_thread+0x50/0x3c0
[54189.371772] ? rescuer_thread+0x380/0x380
[54189.371778] kthread+0x15c/0x180
[54189.371788] ? set_kthread_struct+0x50/0x50
[54189.371797] ret_from_fork+0x22/0x30
[54189.371811] </TASK>
[54189.371820] INFO: task kworker/u16:1:136559 blocked for more than 122 seconds.
[54189.371826] Tainted: G U OE 5.16.3-arch1-1 #1
[54189.371829] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[54189.371832] task:kworker/u16:1 state:D stack: 0 pid:136559 ppid: 2 flags:0x00004000
[54189.371841] Workqueue: netns cleanup_net
[54189.371852] Call Trace:
[54189.371854] <TASK>
[54189.371858] __schedule+0x307/0x10d0
[54189.371867] ? schedule+0x4b/0xd0
[54189.371873] ? wq_worker_running+0xa/0x50
[54189.371881] schedule+0x4b/0xd0
[54189.371887] schedule_preempt_disabled+0x11/0x20
[54189.371894] __mutex_lock.constprop.0+0x256/0x450
[54189.371904] cfg80211_pernet_exit+0xf/0x70 [cfg80211 a54daa6064550d2f8e9fbeda732654ff2f76efba]
[54189.371981] ops_exit_list+0x33/0x70
[54189.371989] cleanup_net+0x213/0x3c0
[54189.371998] process_one_work+0x1e8/0x3c0
[54189.372006] worker_thread+0x50/0x3c0
[54189.372011] ? rescuer_thread+0x380/0x380
[54189.372017] kthread+0x15c/0x180
[54189.372025] ? set_kthread_struct+0x50/0x50
[54189.372035] ret_from_fork+0x22/0x30
[54189.372047] </TASK>
[54189.372050] INFO: task kworker/4:0:137246 blocked for more than 122 seconds.
[54189.372054] Tainted: G U OE 5.16.3-arch1-1 #1
[54189.372057] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[54189.372060] task:kworker/4:0 state:D stack: 0 pid:137246 ppid: 2 flags:0x00004000
[54189.372068] Workqueue: events cfg80211_mgmt_registrations_update_wk [cfg80211]
[54189.372173] Call Trace:
[54189.372175] <TASK>
[54189.372179] __schedule+0x307/0x10d0
[54189.372186] ? update_load_avg+0x7e/0x600
[54189.372198] schedule+0x4b/0xd0
[54189.372204] schedule_preempt_disabled+0x11/0x20
[54189.372210] __mutex_lock.constprop.0+0x256/0x450
[54189.372219] ? __schedule+0x30f/0x10d0
[54189.372227] cfg80211_mgmt_registrations_update_wk+0x1f/0x50 [cfg80211 a54daa6064550d2f8e9fbeda732654ff2f76efba]
[54189.372327] process_one_work+0x1e8/0x3c0
[54189.372334] worker_thread+0x50/0x3c0
[54189.372340] ? rescuer_thread+0x380/0x380
[54189.372345] kthread+0x15c/0x180
[54189.372354] ? set_kthread_struct+0x50/0x50
[54189.372363] ret_from_fork+0x22/0x30
[54189.372375] </TASK>
[54189.372378] INFO: task kworker/4:3:137260 blocked for more than 122 seconds.
[54189.372381] Tainted: G U OE 5.16.3-arch1-1 #1
[54189.372384] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[54189.372386] task:kworker/4:3 state:D stack: 0 pid:137260 ppid: 2 flags:0x00004000
[54189.372394] Workqueue: events linkwatch_event
[54189.372405] Call Trace:
[54189.372407] <TASK>
[54189.372410] __schedule+0x307/0x10d0
[54189.372421] schedule+0x4b/0xd0
[54189.372427] schedule_preempt_disabled+0x11/0x20
[54189.372433] __mutex_lock.constprop.0+0x256/0x450
[54189.372443] linkwatch_event+0xa/0x30
[54189.372452] process_one_work+0x1e8/0x3c0
[54189.372458] worker_thread+0x50/0x3c0
[54189.372464] ? rescuer_thread+0x380/0x380
[54189.372469] kthread+0x15c/0x180
[54189.372477] ? set_kthread_struct+0x50/0x50
[54189.372487] ret_from_fork+0x22/0x30
[54189.372498] </TASK>
[54189.372500] INFO: task kworker/4:4:137263 blocked for more than 122 seconds.
[54189.372504] Tainted: G U OE 5.16.3-arch1-1 #1
[54189.372506] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[54189.372508] task:kworker/4:4 state:D stack: 0 pid:137263 ppid: 2 flags:0x00004000
[54189.372515] Workqueue: events disconnect_work [cfg80211]
[54189.372612] Call Trace:
[54189.372615] <TASK>
[54189.372618] __schedule+0x307/0x10d0
[54189.372628] schedule+0x4b/0xd0
[54189.372634] schedule_preempt_disabled+0x11/0x20
[54189.372640] __mutex_lock.constprop.0+0x256/0x450
[54189.372651] disconnect_work+0x12/0xd0 [cfg80211 a54daa6064550d2f8e9fbeda732654ff2f76efba]
[54189.372749] process_one_work+0x1e8/0x3c0
[54189.372756] worker_thread+0x50/0x3c0
[54189.372762] ? rescuer_thread+0x380/0x380
[54189.372767] kthread+0x15c/0x180
[54189.372775] ? set_kthread_struct+0x50/0x50
[54189.372785] ret_from_fork+0x22/0x30
[54189.372797] </TASK>
[54189.372801] INFO: task iwd:137266 blocked for more than 122 seconds.
[54189.372805] Tainted: G U OE 5.16.3-arch1-1 #1
[54189.372808] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[54189.372810] task:iwd state:D stack: 0 pid:137266 ppid: 1 flags:0x00000000
[54189.372816] Call Trace:
[54189.372818] <TASK>
[54189.372821] __schedule+0x307/0x10d0
[54189.372831] schedule+0x4b/0xd0
[54189.372837] schedule_preempt_disabled+0x11/0x20
[54189.372843] __mutex_lock.constprop.0+0x256/0x450
[54189.372853] nl80211_dump_wiphy+0x22/0x1b0 [cfg80211 a54daa6064550d2f8e9fbeda732654ff2f76efba]
[54189.372946] netlink_dump+0x165/0x2e0
[54189.372960] __netlink_dump_start+0x1b0/0x2e0
[54189.372972] genl_family_rcv_msg_dumpit+0xf4/0x1b0
[54189.372980] ? genl_family_rcv_msg_doit+0x170/0x170
[54189.372986] ? nl80211_send_wiphy+0x2e80/0x2e80 [cfg80211 a54daa6064550d2f8e9fbeda732654ff2f76efba]
[54189.373077] ? genl_family_rcv_msg_dumpit+0x1b0/0x1b0
[54189.373085] genl_rcv_msg+0x161/0x1f0
[54189.373091] ? nl80211_dump_wiphy+0x1b0/0x1b0 [cfg80211 a54daa6064550d2f8e9fbeda732654ff2f76efba]
[54189.373181] ? nl80211_send_wiphy+0x2e80/0x2e80 [cfg80211 a54daa6064550d2f8e9fbeda732654ff2f76efba]
[54189.373269] ? nl80211_register_unexpected_frame+0x50/0x50 [cfg80211 a54daa6064550d2f8e9fbeda732654ff2f76efba]
[54189.373355] ? genl_get_cmd+0x100/0x100
[54189.373362] netlink_rcv_skb+0x5b/0x110
[54189.373375] genl_rcv+0x24/0x40
[54189.373380] netlink_unicast+0x246/0x360
[54189.373391] netlink_sendmsg+0x24f/0x4b0
[54189.373403] sock_sendmsg+0x64/0x70
[54189.373414] __sys_sendto+0x128/0x1a0
[54189.373431] __x64_sys_sendto+0x20/0x40
[54189.373441] do_syscall_64+0x5c/0x90
[54189.373448] ? do_user_addr_fault+0x1d7/0x6a0
[54189.373459] ? syscall_exit_to_user_mode+0x23/0x50
[54189.373470] ? exc_page_fault+0x72/0x180
[54189.373478] entry_SYSCALL_64_after_hwframe+0x44/0xae
[54189.373490] RIP: 0033:0x7fb47b8afc10
[54189.373497] RSP: 002b:00007ffc248a7a58 EFLAGS: 00000246 ORIG_RAX: 000000000000002c
[54189.373504] RAX: ffffffffffffffda RBX: 00005588eae52c80 RCX: 00007fb47b8afc10
[54189.373509] RDX: 0000000000000018 RSI: 00005588eae5d820 RDI: 0000000000000004
[54189.373513] RBP: 00005588eae699c0 R08: 0000000000000000 R09: 0000000000000000
[54189.373517] R10: 0000000000000000 R11: 0000000000000246 R12: 00007ffc248a7af0
[54189.373521] R13: 00007ffc248a7aec R14: 00005588eae5c910 R15: 00005588e95b07a5
[54189.373530] </TASK>