INFO: task hung in process_one

INFO: task hung in process_one_work (4)
Status: upstream: reported syz repro on 2020/08/21 00:08
Reported-by: syzbot+1edb0b6642837b20addf@syzkaller.appspotmail.com
First crash: 388d, last: 27d

Cause bisection: failed (bisect log)

Fix bisection: failed (bisect log)

similar bugs (3):
Kernel	Title	Count	Last	Reported	Patched	Status
upstream	INFO: task hung in process_one_work	1	1108d	1108d	0/22	auto-closed as invalid on 2019/02/22 10:22
upstream	INFO: task hung in process_one_work (3)	1	508d	508d	0/22	closed as invalid on 2019/11/30 16:54
upstream	INFO: task hung in process_one_work (2)	1	673d	673d	0/22	auto-closed as invalid on 2019/10/25 10:51

Sample crash report:

INFO: task kworker/1:8:9838 blocked for more than 143 seconds.
      Not tainted 5.12.0-rc4-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:kworker/1:8     state:D stack:27184 pid: 9838 ppid:     2 flags:0x00004000
Workqueue: events nsim_dev_trap_report_work
Call Trace:
 context_switch kernel/sched/core.c:4322 [inline]
 __schedule+0x999/0xe70 kernel/sched/core.c:5073
 schedule+0x14b/0x200 kernel/sched/core.c:5152
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:5211
 __mutex_lock_common+0x11ef/0x2eb0 kernel/locking/mutex.c:1026
 __mutex_lock kernel/locking/mutex.c:1096 [inline]
 mutex_lock_nested+0x1a/0x20 kernel/locking/mutex.c:1111
 nsim_dev_trap_report_work+0x56/0xb20 drivers/net/netdevsim/dev.c:606
 process_one_work+0x789/0xfd0 kernel/workqueue.c:2275
 worker_thread+0xac1/0x1300 kernel/workqueue.c:2421
 kthread+0x39a/0x3c0 kernel/kthread.c:292
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:294
INFO: task syz-executor.2:9958 blocked for more than 143 seconds.
      Not tainted 5.12.0-rc4-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.2  state:D stack:24952 pid: 9958 ppid:     1 flags:0x00004004
Call Trace:
 context_switch kernel/sched/core.c:4322 [inline]
 __schedule+0x999/0xe70 kernel/sched/core.c:5073
 schedule+0x14b/0x200 kernel/sched/core.c:5152
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:5211
 __mutex_lock_common+0x11ef/0x2eb0 kernel/locking/mutex.c:1026
 __mutex_lock kernel/locking/mutex.c:1096 [inline]
 mutex_lock_nested+0x1a/0x20 kernel/locking/mutex.c:1111
 genl_lock net/netlink/genetlink.c:33 [inline]
 genl_rcv_msg+0xb1/0x1280 net/netlink/genetlink.c:798
 netlink_rcv_skb+0x190/0x3a0 net/netlink/af_netlink.c:2502
 genl_rcv+0x24/0x40 net/netlink/genetlink.c:811
 netlink_unicast_kernel net/netlink/af_netlink.c:1312 [inline]
 netlink_unicast+0x786/0x940 net/netlink/af_netlink.c:1338
 netlink_sendmsg+0x9ae/0xd50 net/netlink/af_netlink.c:1927
 sock_sendmsg_nosec net/socket.c:654 [inline]
 sock_sendmsg net/socket.c:674 [inline]
 __sys_sendto+0x438/0x5c0 net/socket.c:1977
 __do_sys_sendto net/socket.c:1989 [inline]
 __se_sys_sendto net/socket.c:1985 [inline]
 __x64_sys_sendto+0xda/0xf0 net/socket.c:1985
 do_syscall_64+0x2d/0x70 arch/x86/entry/common.c:46
 entry_SYSCALL_64_after_hwframe+0x44/0xae
RIP: 0033:0x4193ec
RSP: 002b:00007ffd9b2c40b0 EFLAGS: 00000293
 ORIG_RAX: 000000000000002c
RAX: ffffffffffffffda RBX: 00000000014a4320 RCX: 00000000004193ec
RDX: 0000000000000024 RSI: 00000000014a4370 RDI: 0000000000000003
RBP: 0000000000000000 R08: 00007ffd9b2c4104 R09: 000000000000000c
R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000000
R13: 00000000014a4370 R14: 0000000000000003 R15: 0000000000000000

Showing all locks held in the system:
1 lock held by khungtaskd/1616:
 #0: ffffffff8c710180
 (rcu_read_lock){....}-{1:2}, at: rcu_lock_acquire+0x0/0x30 arch/x86/pci/mmconfig_64.c:151
1 lock held by khugepaged/1636:
 #0: 
ffffffff8c7a1cc8 (lock#5){+.+.}-{3:3}, at: lru_add_drain_all+0x63/0x930 mm/swap.c:777
1 lock held by in:imklog/8050:
 #0: ffff888013a405f0 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0x24e/0x2f0 fs/file.c:961
3 locks held by kworker/0:0/8394:
 #0: 
ffff88802186c938
 (
(wq_completion)ipv6_addrconf){+.+.}-{0:0}, at: process_one_work+0x6f4/0xfd0 kernel/workqueue.c:2248
 #1: ffffc90001c47d78 ((work_completion)(&(&ifa->dad_work)->work)){+.+.}-{0:0}, at: process_one_work+0x733/0xfd0 kernel/workqueue.c:2250
 #2: ffffffff8d70ac28 (rtnl_mutex){+.+.}-{3:3}, at: addrconf_dad_work+0x61/0x1d00 net/ipv6/addrconf.c:4031
3 locks held by kworker/u4:0/8469:
3 locks held by kworker/1:0/8576:
 #0: ffff888010864d38 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x6f4/0xfd0 kernel/workqueue.c:2248
 #1: ffffc900022d7d78 (deferred_process_work){+.+.}-{0:0}, at: process_one_work+0x733/0xfd0 kernel/workqueue.c:2250
 #2: ffffffff8d70ac28 (rtnl_mutex){+.+.}-{3:3}, at: switchdev_deferred_process_work+0xa/0x20 net/switchdev/switchdev.c:74
3 locks held by kworker/1:5/9702:
 #0: ffff88802186c938 ((wq_completion)ipv6_addrconf){+.+.}-{0:0}, at: process_one_work+0x6f4/0xfd0 kernel/workqueue.c:2248
 #1: ffffc9000acdfd78 ((work_completion)(&(&ifa->dad_work)->work)){+.+.}-{0:0}, at: process_one_work+0x733/0xfd0 kernel/workqueue.c:2250
 #2: 
ffffffff8d70ac28
 (rtnl_mutex
){+.+.}-{3:3}, at: addrconf_dad_work+0x61/0x1d00 net/ipv6/addrconf.c:4031
3 locks held by kworker/0:6/9732:
6 locks held by kworker/u4:4/9737:
 #0: ffff8881407b3138 ((wq_completion)netns){+.+.}-{0:0}, at: process_one_work+0x6f4/0xfd0 kernel/workqueue.c:2248
 #1: ffffc9000ae1fd78 (net_cleanup_work){+.+.}-{0:0}, at: process_one_work+0x733/0xfd0 kernel/workqueue.c:2250
 #2: ffffffff8d6ff070 (pernet_ops_rwsem){++++}-{3:3}, at: cleanup_net+0xac/0xbd0 net/core/net_namespace.c:557
 #3: 
ffffffff8d72f4e8 (devlink_mutex){+.+.}-{3:3}, at: devlink_pernet_pre_exit+0x32/0x1d0 net/core/devlink.c:10579
 #4: ffff888013cf6390 (&nsim_dev->port_list_lock){+.+.}-{3:3}, at: nsim_dev_port_del_all drivers/net/netdevsim/dev.c:977 [inline]
 #4: ffff888013cf6390 (&nsim_dev->port_list_lock){+.+.}-{3:3}, at: nsim_dev_reload_destroy+0x83/0x2e0 drivers/net/netdevsim/dev.c:1160
 #5: ffffffff8d70ac28 (rtnl_mutex
){+.+.}-{3:3}, at: netdev_run_todo+0xe3a/0x1010 net/core/dev.c:10469
3 locks held by kworker/1:8/9838:
 #0: ffff888010864d38 ((wq_completion)events){+.+.}-{0:0}, at: process_one_work+0x6f4/0xfd0 kernel/workqueue.c:2248
 #1: ffffc9000b0efd78 ((work_completion)(&(&nsim_dev->trap_data->trap_report_dw)->work)){+.+.}-{0:0}, at: process_one_work+0x733/0xfd0 kernel/workqueue.c:2250
 #2: ffff888013cf6390 (&nsim_dev->port_list_lock){+.+.}-{3:3}, at: nsim_dev_trap_report_work+0x56/0xb20 drivers/net/netdevsim/dev.c:606
2 locks held by kworker/1:9/9880:
 #0: ffff888011603938 ((wq_completion)cgroup_destroy){+.+.}-{0:0}, at: process_one_work+0x6f4/0xfd0 kernel/workqueue.c:2248
 #1: 
ffffc9000b2cfd78
 ((work_completion)(&(&css->destroy_rwork)->work)){+.+.}-{0:0}, at: process_one_work+0x733/0xfd0 kernel/workqueue.c:2250
1 lock held by syz-executor.1/9954:
 #0: ffffffff8d70ac28 (rtnl_mutex){+.+.}-{3:3}, at: tun_detach drivers/net/tun.c:676 [inline]
 #0: ffffffff8d70ac28 (rtnl_mutex){+.+.}-{3:3}, at: tun_chr_close+0x3c/0x130 drivers/net/tun.c:3347
2 locks held by syz-executor.3/9957:
 #0: ffffffff8d70ac28 (rtnl_mutex){+.+.}-{3:3}, at: tun_detach drivers/net/tun.c:676 [inline]
 #0: ffffffff8d70ac28 (rtnl_mutex){+.+.}-{3:3}, at: tun_chr_close+0x3c/0x130 drivers/net/tun.c:3347
 #1: ffffffff8c714768 (rcu_state.exp_mutex){+.+.}-{3:3}, at: exp_funnel_lock kernel/rcu/tree_exp.h:290 [inline]
 #1: ffffffff8c714768 (rcu_state.exp_mutex){+.+.}-{3:3}, at: synchronize_rcu_expedited+0x1e8/0x610 kernel/rcu/tree_exp.h:836
2 locks held by syz-executor.2/9958:
 #0: ffffffff8d767e90 (cb_lock){++++}-{3:3}, at: genl_rcv+0x15/0x40 net/netlink/genetlink.c:810
 #1: ffffffff8d767d48 (genl_mutex){+.+.}-{3:3}, at: genl_lock net/netlink/genetlink.c:33 [inline]
 #1: ffffffff8d767d48 (genl_mutex){+.+.}-{3:3}, at: genl_rcv_msg+0xb1/0x1280 net/netlink/genetlink.c:798
1 lock held by syz-executor.4/9959:
 #0: ffffffff8d70ac28 (rtnl_mutex){+.+.}-{3:3}, at: netdev_run_todo+0xe3a/0x1010 net/core/dev.c:10469
3 locks held by syz-executor.0/9961:
 #0: ffffffff8d767e90 (cb_lock){++++}-{3:3}, at: genl_rcv+0x15/0x40 net/netlink/genetlink.c:810
 #1: ffffffff8d767d48 (genl_mutex){+.+.}-{3:3}, at: genl_lock net/netlink/genetlink.c:33 [inline]
 #1: ffffffff8d767d48 (genl_mutex){+.+.}-{3:3}, at: genl_rcv_msg+0xb1/0x1280 net/netlink/genetlink.c:798
 #2: ffffffff8d70ac28 (rtnl_mutex){+.+.}-{3:3}, at: ieee80211_register_hw+0x2175/0x3890 net/mac80211/main.c:1213

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

NMI backtrace for cpu 1
CPU: 1 PID: 1616 Comm: khungtaskd Not tainted 5.12.0-rc4-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 __dump_stack lib/dump_stack.c:79 [inline]
 dump_stack+0x176/0x24e lib/dump_stack.c:120
 nmi_cpu_backtrace+0x16c/0x190 lib/nmi_backtrace.c:105
 nmi_trigger_cpumask_backtrace+0x191/0x2f0 lib/nmi_backtrace.c:62
 trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:209 [inline]
 watchdog+0xcfb/0xd40 kernel/hung_task.c:294
 kthread+0x39a/0x3c0 kernel/kthread.c:292
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:294
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 9732 Comm: kworker/0:6 Not tainted 5.12.0-rc4-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Workqueue: events uhid_device_add_worker
RIP: 0010:io_serial_in+0x71/0xb0 drivers/tty/serial/8250/8250_port.c:447
Code: 95 ef 39 fd 89 e9 41 d3 e6 48 83 c3 40 48 89 d8 48 c1 e8 03 42 80 3c 38 00 74 08 48 89 df e8 b6 c7 7d fd 44 03 33 44 89 f2 ec <0f> b6 c0 5b 41 5e 41 5f 5d c3 89 e9 80 e1 07 38 c1 7c ad 48 89 ef
RSP: 0018:ffffc9000addf320 EFLAGS: 00000002
RAX: 1ffffffff2069400 RBX: ffffffff9034a480 RCX: 0000000000000000
RDX: 00000000000003fd RSI: 0000000000000000 RDI: 0000000000000020
RBP: 0000000000000000 R08: ffffffff843f1eb1 R09: fffff520015bbe70
R10: fffff520015bbe70 R11: 0000000000000000 R12: 0000000000000020
R13: ffffffff9034a440 R14: 00000000000003fd R15: dffffc0000000000
FS:  0000000000000000(0000) GS:ffff8880b9c00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007ff6d3331020 CR3: 0000000025db2000 CR4: 00000000001506f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 serial_in drivers/tty/serial/8250/8250.h:113 [inline]
 wait_for_xmitr+0xeb/0x280 drivers/tty/serial/8250/8250_port.c:2061
 serial8250_console_putchar+0x19/0x50 drivers/tty/serial/8250/8250_port.c:3244
 uart_console_write+0x9c/0xf0 drivers/tty/serial/serial_core.c:1943
 serial8250_console_write+0x971/0xd20 drivers/tty/serial/8250/8250_port.c:3316
 call_console_drivers kernel/printk/printk.c:1858 [inline]
 console_unlock+0x930/0xe00 kernel/printk/printk.c:2576
 vprintk_emit+0x1ab/0x270 kernel/printk/printk.c:2098
 dev_vprintk_emit+0x246/0x2a5 drivers/base/core.c:4434
 dev_printk_emit+0x6a/0x8c drivers/base/core.c:4445
 _dev_warn+0xb9/0xdb drivers/base/core.c:4501
 hid_parser_main+0xab0/0xf50 drivers/hid/hid-core.c:630
 hid_open_report+0x71c/0xe60 drivers/hid/hid-core.c:1260
 hid_parse include/linux/hid.h:1043 [inline]
 hid_generic_probe+0x38/0x80 drivers/hid/hid-generic.c:63
 hid_device_probe+0x26c/0x410 drivers/hid/hid-core.c:2284
 really_probe+0x45f/0x13d0 drivers/base/dd.c:554
 driver_probe_device+0x15a/0x310 drivers/base/dd.c:740
 bus_for_each_drv+0x108/0x170 drivers/base/bus.c:431
 __device_attach+0x2cb/0x480 drivers/base/dd.c:914
 bus_probe_device+0xb8/0x1f0 drivers/base/bus.c:491
 device_add+0x1240/0x1670 drivers/base/core.c:3242
 hid_add_device+0xa2a/0xef0 drivers/hid/hid-core.c:2440
 uhid_device_add_worker+0x40/0x100 drivers/hid/uhid.c:62
 process_one_work+0x789/0xfd0 kernel/workqueue.c:2275
 worker_thread+0xac1/0x1300 kernel/workqueue.c:2421
 kthread+0x39a/0x3c0 kernel/kthread.c:292
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:294

Crashes (12):
Manager	Time	Kernel	Commit	Syzkaller	Config	Log	Report	Syz repro	VM info	Title
ci-upstream-kasan-gce-smack-root	2021/03/25 04:33	upstream	4ee998b0	607e3baf	.config	log	report	syz		INFO: task hung in process_one_work
ci-upstream-kasan-gce	2021/02/26 22:23	upstream	2c87f7a3	4c37c133	.config	log	report	syz		INFO: task hung in process_one_work
ci-upstream-kasan-gce-root	2020/08/17 21:22	upstream	9123e3a7	424dd8e7	.config	log	report	syz
ci-upstream-kasan-gce-selinux-root	2020/08/16 23:58	upstream	4b6c093e	424dd8e7	.config	log	report	syz
ci-upstream-kasan-gce-386	2020/08/21 17:34	upstream	da2968ff	6436ce4b	.config	log	report	syz
ci-upstream-kasan-gce-root	2021/03/02 05:51	upstream	7a7fd0de	183afb6c	.config	log	report		info	INFO: task hung in process_one_work
ci-upstream-kasan-gce-root	2021/02/28 05:39	upstream	5695e516	4c37c133	.config	log	report		info	INFO: task hung in process_one_work
ci-upstream-kasan-gce-root	2020/05/28 07:19	upstream	b0c3ba31	142a0957	.config	log	report
ci-upstream-kasan-gce-smack-root	2020/03/29 14:05	upstream	906c4043	05736b29	.config	log	report
ci-upstream-bpf-next-kasan-gce	2020/11/08 08:41	bpf-next	f055f355	64069d48	.config	log	report		info
ci-upstream-net-kasan-gce	2020/04/09 07:55	net-next	63bef48f	a8c6a3f8	.config	log	report
ci-upstream-linux-next-kasan-gce-root	2020/07/20 13:06	linux-next	ab8be66e	4285ffa3	.config	log	report