Dear developers and maintainers,
We originally encountered a task hung while using our modified
syzkaller. It was tested against the latest upstream kernel. We
analyzed the root cause and pinpoint the kernel crash log to the
following two tasks.
```
INFO: task systemd-rfkill:49424 blocked for more than 143 seconds.
Tainted: G U 6.12.0-09435-g2c22dc1ee3a1 #11
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:systemd-rfkill state:D stack:25264 pid:49424 tgid:49424 ppid:1
flags:0x00000000
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5369 [inline]
__schedule+0xe3b/0x5ac0 kernel/sched/core.c:6756
__schedule_loop kernel/sched/core.c:6833 [inline]
schedule+0xe7/0x350 kernel/sched/core.c:6848
schedule_preempt_disabled+0x13/0x30 kernel/sched/core.c:6905
__mutex_lock_common kernel/locking/mutex.c:665 [inline]
__mutex_lock+0x59e/0xa50 kernel/locking/mutex.c:735
device_lock include/linux/device.h:1014 [inline]
nfc_dev_down+0x2d/0x2e0 net/nfc/core.c:143
nfc_rfkill_set_block+0x39/0xe0 net/nfc/core.c:179
rfkill_set_block+0x211/0x560 net/rfkill/core.c:346
rfkill_fop_write+0x47b/0x570 net/rfkill/core.c:1309
vfs_write+0x2b6/0x10d0 fs/read_write.c:677
ksys_write+0x1fe/0x240 fs/read_write.c:731
do_syscall_x64 arch/x86/entry/common.c:52 [inline]
do_syscall_64+0xcb/0x250 arch/x86/entry/common.c:83
entry_SYSCALL_64_after_hwframe+0x77/0x7f
RIP: 0033:0x7fa86ef8b473
RSP: 002b:00007fff7ad75778 EFLAGS: 00000246 ORIG_RAX: 0000000000000001
RAX: ffffffffffffffda RBX: 00007fff7ad757a0 RCX: 00007fa86ef8b473
RDX: 0000000000000008 RSI: 00007fff7ad757a8 RDI: 0000000000000003
RBP: 000055ce3e070c20 R08: 0000000000000000 R09: 00000000ffffffff
R10: 0000000000000004 R11: 0000000000000246 R12: 00007fff7ad757a8
R13: 0000000000000001 R14: 0000000000000001 R15: 000055ce3e06f072
</TASK>
INFO: task syz-executor.3:50072 blocked for more than 143 seconds.
Tainted: G U 6.12.0-09435-g2c22dc1ee3a1 #11
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.3 state:D stack:26808 pid:50072 tgid:50072
ppid:45742 flags:0x00004006
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5369 [inline]
__schedule+0xe3b/0x5ac0 kernel/sched/core.c:6756
__schedule_loop kernel/sched/core.c:6833 [inline]
schedule+0xe7/0x350 kernel/sched/core.c:6848
schedule_preempt_disabled+0x13/0x30 kernel/sched/core.c:6905
__mutex_lock_common kernel/locking/mutex.c:665 [inline]
__mutex_lock+0x59e/0xa50 kernel/locking/mutex.c:735
rfkill_unregister+0xde/0x2c0 net/rfkill/core.c:1145
nfc_unregister_device+0x96/0x330 net/nfc/core.c:1167
virtual_ncidev_close+0x4c/0xa0 drivers/nfc/virtual_ncidev.c:172
__fput+0x3fb/0xb40 fs/file_table.c:450
__fput_sync+0xa6/0xc0 fs/file_table.c:535
__do_sys_close fs/open.c:1554 [inline]
__se_sys_close fs/open.c:1539 [inline]
__x64_sys_close+0x8a/0x120 fs/open.c:1539
do_syscall_x64 arch/x86/entry/common.c:52 [inline]
do_syscall_64+0xcb/0x250 arch/x86/entry/common.c:83
entry_SYSCALL_64_after_hwframe+0x77/0x7f
RIP: 0033:0x7f2ce729134b
RSP: 002b:00007ffcf599f720 EFLAGS: 00000293 ORIG_RAX: 0000000000000003
RAX: ffffffffffffffda RBX: 0000000000000005 RCX: 00007f2ce729134b
RDX: 0000000000000000 RSI: 000000000000c56e RDI: 0000000000000004
RBP: 00007f2ce73dd980 R08: 0000000000000000 R09: 000000008b1393d5
R10: 0000000000000001 R11: 0000000000000293 R12: 00000000000bde95
R13: 00007ffcf599f820 R14: 00007f2ce6e01e30 R15: 00007f2ce6e01e28
</TASK>
```
After analyzing the log, we found that it was actually a deadlock
between nfc_unregister_device() and rfkill_fop_write():
CPU0 CPU1
-------------------------------------------------------
rfkill_fop_write nfc_unregister_device
mutex_lock(rfkill_global_mutex) device_lock
rfkill_set_block rfkill_unregister
nfc_rfkill_ser_block
mutex_lock(rfkill_global_mutex)
nfc_device_down
device_lock
------------------------------------------------------
If you have any questions, please contact us.
Best Regards,
Yue
