[v6.1] INFO: task hung in nfc_targets_found

[syzbot]

Hello,

syzbot found the following issue on:

HEAD commit: fa74641fb6b9 Linux 6.1.29
git tree: linux-6.1.y
console output: https://syzkaller.appspot.com/x/log.txt?x=11780e86280000
kernel config: https://syzkaller.appspot.com/x/.config?x=fac5c36c2b16009f
dashboard link: https://syzkaller.appspot.com/bug?extid=0fd72d3004e14dbe500a
compiler: Debian clang version 15.0.7, GNU ld (GNU Binutils for Debian) 2.35.2

Unfortunately, I don't have any reproducer for this issue yet.

Downloadable assets:
disk image: https://storage.googleapis.com/syzbot-assets/3e78f005d7f8/disk-fa74641f.raw.xz
vmlinux: https://storage.googleapis.com/syzbot-assets/6527fcf66401/vmlinux-fa74641f.xz
kernel image: https://storage.googleapis.com/syzbot-assets/c5e0d5f8b434/bzImage-fa74641f.xz

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+0fd72d...@syzkaller.appspotmail.com

INFO: task kworker/u4:0:9 blocked for more than 144 seconds.
Not tainted 6.1.29-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/u4:0 state:D stack:20832 pid:9 ppid:2 flags:0x00004000
Workqueue: nfc2_nci_rx_wq nci_rx_work
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5241 [inline]
__schedule+0x132c/0x4330 kernel/sched/core.c:6554
schedule+0xbf/0x180 kernel/sched/core.c:6630
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6689
__mutex_lock_common+0xe2b/0x2520 kernel/locking/mutex.c:679
__mutex_lock kernel/locking/mutex.c:747 [inline]
mutex_lock_nested+0x17/0x20 kernel/locking/mutex.c:799
device_lock include/linux/device.h:836 [inline]
nfc_targets_found+0x26b/0x580 net/nfc/core.c:778
nci_ntf_packet+0x42e4/0x4db0
nci_rx_work+0xf7/0x260 net/nfc/nci/core.c:1513
process_one_work+0x8aa/0x11f0 kernel/workqueue.c:2289
worker_thread+0xa5f/0x1210 kernel/workqueue.c:2436
kthread+0x26e/0x300 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:306
</TASK>
INFO: task kworker/1:6:3640 blocked for more than 145 seconds.
Not tainted 6.1.29-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/1:6 state:D stack:26776 pid:3640 ppid:2 flags:0x00004000
Workqueue: events nfc_urelease_event_work
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5241 [inline]
__schedule+0x132c/0x4330 kernel/sched/core.c:6554
schedule+0xbf/0x180 kernel/sched/core.c:6630
schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:6689
__mutex_lock_common+0xe2b/0x2520 kernel/locking/mutex.c:679
__mutex_lock kernel/locking/mutex.c:747 [inline]
mutex_lock_nested+0x17/0x20 kernel/locking/mutex.c:799
nci_request net/nfc/nci/core.c:148 [inline]
nci_stop_poll+0x11f/0x480 net/nfc/nci/core.c:872
nfc_stop_poll+0xe6/0x220 net/nfc/core.c:259
nfc_urelease_event_work+0x162/0x2f0 net/nfc/netlink.c:1842
process_one_work+0x8aa/0x11f0 kernel/workqueue.c:2289
worker_thread+0xa5f/0x1210 kernel/workqueue.c:2436
kthread+0x26e/0x300 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:306
</TASK>
INFO: task syz-executor.4:11301 blocked for more than 146 seconds.
Not tainted 6.1.29-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.4 state:D stack:25744 pid:11301 ppid:3595 flags:0x00004006
Call Trace:
<TASK>
context_switch kernel/sched/core.c:5241 [inline]
__schedule+0x132c/0x4330 kernel/sched/core.c:6554
schedule+0xbf/0x180 kernel/sched/core.c:6630
schedule_timeout+0xac/0x300 kernel/time/timer.c:1911
do_wait_for_common+0x441/0x5e0 kernel/sched/completion.c:85
__wait_for_common kernel/sched/completion.c:106 [inline]
wait_for_common kernel/sched/completion.c:117 [inline]
wait_for_completion+0x46/0x60 kernel/sched/completion.c:138
__flush_workqueue+0x737/0x1610 kernel/workqueue.c:2861
nci_close_device+0x185/0x5f0 net/nfc/nci/core.c:578
nci_unregister_device+0x3c/0x230 net/nfc/nci/core.c:1291
virtual_ncidev_close+0x55/0x90 drivers/nfc/virtual_ncidev.c:166
__fput+0x3b7/0x890 fs/file_table.c:320
task_work_run+0x246/0x300 kernel/task_work.c:179
get_signal+0x15fc/0x17d0 kernel/signal.c:2635
arch_do_signal_or_restart+0xb0/0x1a10 arch/x86/kernel/signal.c:869
exit_to_user_mode_loop+0x6a/0x100 kernel/entry/common.c:168
exit_to_user_mode_prepare+0xb1/0x140 kernel/entry/common.c:204
__syscall_exit_to_user_mode_work kernel/entry/common.c:286 [inline]
syscall_exit_to_user_mode+0x60/0x270 kernel/entry/common.c:297
do_syscall_64+0x49/0xb0 arch/x86/entry/common.c:86
entry_SYSCALL_64_after_hwframe+0x63/0xcd
RIP: 0033:0x7fb5e1c8c169
RSP: 002b:00007fb5e29e0168 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
RAX: fffffffffffffff2 RBX: 00007fb5e1dabf80 RCX: 00007fb5e1c8c169
RDX: 0000000000000064 RSI: 0000000020000840 RDI: 0000000000000003
RBP: 00007fb5e1ce7ca1 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000000
R13: 00007fff7217e33f R14: 00007fb5e29e0300 R15: 0000000000022000
</TASK>

Showing all locks held in the system:
3 locks held by kworker/u4:0/9:
#0: ffff888078624938 ((wq_completion)nfc2_nci_rx_wq){+.+.}-{0:0}, at: process_one_work+0x77a/0x11f0
#1: ffffc900000e7d20 ((work_completion)(&ndev->rx_work)){+.+.}-{0:0}, at: process_one_work+0x7bd/0x11f0 kernel/workqueue.c:2264
#2: ffff88801fe7f100 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:836 [inline]
#2: ffff88801fe7f100 (&dev->mutex){....}-{3:3}, at: nfc_targets_found+0x26b/0x580 net/nfc/core.c:778
1 lock held by rcu_tasks_kthre/12:
#0: ffffffff8cf274b0 (rcu_tasks.tasks_gp_mutex){+.+.}-{3:3}, at: rcu_tasks_one_gp+0x29/0xd20 kernel/rcu/tasks.h:510
1 lock held by rcu_tasks_trace/13:
#0: ffffffff8cf27cb0 (rcu_tasks_trace.tasks_gp_mutex){+.+.}-{3:3}, at: rcu_tasks_one_gp+0x29/0xd20 kernel/rcu/tasks.h:510
3 locks held by kworker/0:1/14:
#0: ffff888012464d38 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x77a/0x11f0
#1: ffffc90000137d20 ((work_completion)(&w->w)){+.+.}-{0:0}, at: process_one_work+0x7bd/0x11f0 kernel/workqueue.c:2264
#2: ffffffff8e3894e8 (nfc_devlist_mutex){+.+.}-{3:3}, at: nfc_urelease_event_work+0xa9/0x2f0 net/nfc/netlink.c:1833
1 lock held by khungtaskd/28:
#0: ffffffff8cf272e0 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire+0x0/0x30
4 locks held by kworker/u4:2/35:
2 locks held by kworker/1:2/150:
#0: ffff888012464d38 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x77a/0x11f0
#1: ffffc90002eefd20 ((work_completion)(&dev->recv_work)){+.+.}-{0:0}, at: process_one_work+0x7bd/0x11f0 kernel/workqueue.c:2264
2 locks held by getty/3306:
#0: ffff8880288a4098 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x21/0x70 drivers/tty/tty_ldisc.c:244
#1: ffffc900031262f0 (&ldata->atomic_read_lock){+.+.}-{3:3}, at: n_tty_read+0x6a7/0x1db0 drivers/tty/n_tty.c:2177
2 locks held by syz-executor.0/3578:
#0: ffff8880142da0e0 (&type->s_umount_key#63){+.+.}-{3:3}, at: deactivate_super+0xa9/0xe0 fs/super.c:362
#1: ffffffff8cf2c8b8 (rcu_state.exp_mutex){+.+.}-{3:3}, at: exp_funnel_lock kernel/rcu/tree_exp.h:292 [inline]
#1: ffffffff8cf2c8b8 (rcu_state.exp_mutex){+.+.}-{3:3}, at: synchronize_rcu_expedited+0x3b0/0x8a0 kernel/rcu/tree_exp.h:948
6 locks held by kworker/1:6/3640:
#0: ffff888012464d38 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x77a/0x11f0
#1: ffffc900046dfd20 ((work_completion)(&w->w)){+.+.}-{0:0}, at: process_one_work+0x7bd/0x11f0 kernel/workqueue.c:2264
#2: ffffffff8e3894e8 (nfc_devlist_mutex){+.+.}-{3:3}, at: nfc_urelease_event_work+0xa9/0x2f0 net/nfc/netlink.c:1833
#3: ffff88801fe7f508 (&genl_data->genl_data_mutex){+.+.}-{3:3}, at: nfc_urelease_event_work+0x113/0x2f0 net/nfc/netlink.c:1839
#4: ffff88801fe7f100 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:836 [inline]
#4: ffff88801fe7f100 (&dev->mutex){....}-{3:3}, at: nfc_stop_poll+0x38/0x220 net/nfc/core.c:247
#5: ffff888049159350 (&ndev->req_lock){+.+.}-{3:3}, at: nci_request net/nfc/nci/core.c:148 [inline]
#5: ffff888049159350 (&ndev->req_lock){+.+.}-{3:3}, at: nci_stop_poll+0x11f/0x480 net/nfc/nci/core.c:872
3 locks held by kworker/1:12/4208:
#0: ffff888012464d38 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x77a/0x11f0
#1: ffffc9000b39fd20 ((work_completion)(&w->w)){+.+.}-{0:0}, at: process_one_work+0x7bd/0x11f0 kernel/workqueue.c:2264
#2: ffffffff8e3894e8 (nfc_devlist_mutex){+.+.}-{3:3}, at: nfc_urelease_event_work+0xa9/0x2f0 net/nfc/netlink.c:1833
3 locks held by kworker/1:13/4209:
#0: ffff888012464d38 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x77a/0x11f0
#1: ffffc9000b3afd20 ((work_completion)(&w->w)){+.+.}-{0:0}, at: process_one_work+0x7bd/0x11f0 kernel/workqueue.c:2264
#2: ffffffff8e3894e8 (nfc_devlist_mutex){+.+.}-{3:3}, at: nfc_urelease_event_work+0xa9/0x2f0 net/nfc/netlink.c:1833
3 locks held by kworker/0:14/7764:
#0: ffff888012464d38 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x77a/0x11f0
#1: ffffc90015b87d20 ((work_completion)(&w->w)){+.+.}-{0:0}, at: process_one_work+0x7bd/0x11f0 kernel/workqueue.c:2264
#2: ffffffff8e3894e8 (nfc_devlist_mutex){+.+.}-{3:3}, at: nfc_urelease_event_work+0xa9/0x2f0 net/nfc/netlink.c:1833
2 locks held by kworker/0:17/7769:
#0: ffff888012466538 ((wq_completion)rcu_gp){+.+.}-{0:0}, at: process_one_work+0x77a/0x11f0
#1: ffffc90015e37d20 ((work_completion)(&rew->rew_work)){+.+.}-{0:0}, at: process_one_work+0x7bd/0x11f0 kernel/workqueue.c:2264
1 lock held by syz-executor.4/11301:
#0: ffff888049159350 (&ndev->req_lock){+.+.}-{3:3}, at: nci_close_device+0x106/0x5f0 net/nfc/nci/core.c:560
1 lock held by syz-executor.2/12641:
#0: ffff88801e61e620 (&iint->mutex){+.+.}-{3:3}, at: ima_check_last_writer security/integrity/ima/ima_main.c:164 [inline]
#0: ffff88801e61e620 (&iint->mutex){+.+.}-{3:3}, at: ima_file_free+0x10c/0x3c0 security/integrity/ima/ima_main.c:198
1 lock held by syz-executor.2/12642:
#0: ffffffff8d673dc8 (reading_mutex){+.+.}-{3:3}, at: rng_dev_read+0xee/0x5a0 drivers/char/hw_random/core.c:230
2 locks held by syz-executor.2/12643:
1 lock held by syz-executor.3/12661:
#0: ffff888029240e00 (&iint->mutex){+.+.}-{3:3}, at: ima_check_last_writer security/integrity/ima/ima_main.c:164 [inline]
#0: ffff888029240e00 (&iint->mutex){+.+.}-{3:3}, at: ima_file_free+0x10c/0x3c0 security/integrity/ima/ima_main.c:198
1 lock held by syz-executor.3/12662:
#0: ffffffff8d673dc8 (reading_mutex){+.+.}-{3:3}, at: rng_dev_read+0xee/0x5a0 drivers/char/hw_random/core.c:230
2 locks held by syz-executor.3/12664:

=============================================

NMI backtrace for cpu 0
CPU: 0 PID: 28 Comm: khungtaskd Not tainted 6.1.29-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 04/28/2023
Call Trace:
<TASK>
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0x1e3/0x2cb lib/dump_stack.c:106
nmi_cpu_backtrace+0x4e1/0x560 lib/nmi_backtrace.c:111
nmi_trigger_cpumask_backtrace+0x1b0/0x3f0 lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:148 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:220 [inline]
watchdog+0xf18/0xf60 kernel/hung_task.c:377
kthread+0x26e/0x300 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:306
</TASK>
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 3635 Comm: kworker/1:4 Not tainted 6.1.29-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 04/28/2023
Workqueue: events nsim_dev_trap_report_work
RIP: 0010:unwind_next_frame+0xbe4/0x2220
Code: b6 75 01 83 e6 03 83 fe 02 0f 84 28 02 00 00 83 fe 01 0f 84 99 03 00 00 85 f6 0f 85 01 05 00 00 48 89 54 24 48 48 89 5c 24 58 <4c> 89 7c 24 50 48 89 6c 24 10 49 8d 5c 24 08 49 89 df 49 c1 ef 03
RSP: 0018:ffffc9000468f640 EFLAGS: 00000246
RAX: 0000000000000000 RBX: ffffffff8ed7c143 RCX: ffffffff8e6944a0
RDX: 1ffffffff1daf828 RSI: 0000000000000000 RDI: dffffc0000000000
RBP: ffffffff8ed7c13e R08: 0000000000000013 R09: ffffc9000468f810
R10: 0000000000000000 R11: dffffc0000000001 R12: ffffc9000468f720
R13: ffffffff8ed7c142 R14: ffffffff8e69449c R15: 1ffffffff1daf828
FS: 0000000000000000(0000) GS:ffff8880b9900000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 000000c0077e6000 CR3: 000000000cc8e000 CR4: 00000000003506e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
<TASK>
arch_stack_walk+0x10d/0x140 arch/x86/kernel/stacktrace.c:25
stack_trace_save+0x113/0x1c0 kernel/stacktrace.c:122
kasan_save_stack mm/kasan/common.c:45 [inline]
kasan_set_track+0x4b/0x70 mm/kasan/common.c:52
kasan_save_free_info+0x27/0x40 mm/kasan/generic.c:516
____kasan_slab_free+0xd6/0x120 mm/kasan/common.c:236
kasan_slab_free include/linux/kasan.h:177 [inline]
slab_free_hook mm/slub.c:1724 [inline]
slab_free_freelist_hook mm/slub.c:1750 [inline]
slab_free mm/slub.c:3661 [inline]
kmem_cache_free+0x292/0x510 mm/slub.c:3683
nsim_dev_trap_report drivers/net/netdevsim/dev.c:824 [inline]
nsim_dev_trap_report_work+0x75d/0xa90 drivers/net/netdevsim/dev.c:853
process_one_work+0x8aa/0x11f0 kernel/workqueue.c:2289
worker_thread+0xa5f/0x1210 kernel/workqueue.c:2436
kthread+0x26e/0x300 kernel/kthread.c:376
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:306
</TASK>


---
This report is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at syzk...@googlegroups.com.

syzbot will keep track of this issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.

If the bug is already fixed, let syzbot know by replying with:
#syz fix: exact-commit-title

If you want to change bug's subsystems, reply with:
#syz set subsystems: new-subsystem
(See the list of subsystem names on the web dashboard)

If the bug is a duplicate of another bug, reply with:
#syz dup: exact-subject-of-another-report

If you want to undo deduplication, reply with:
#syz undup

[syzbot]

Auto-closing this bug as obsolete.
Crashes did not happen for a while, no reproducer and no activity.