INFO: task hung in lru_add_drain

INFO: task hung in lru_add_drain_all
Status: upstream: reported C repro on 2020/07/04 23:22
Reported-by: syzbot+1053252c4289b5f73548@syzkaller.appspotmail.com
First crash: 308d, last: 13d

Cause bisection: introduced by (bisect log) [ignored commit]:
commit f2c2e717642c66f7fe7e5dd69b2e8ff5849f4d10
Author: Andrey Konovalov <andreyknvl@google.com>
Date: Mon Feb 24 16:13:03 2020 +0000

usb: gadget: add raw-gadget interface

Crash: INFO: task hung in synchronize_rcu (log)
Repro: C syz .config

similar bugs (1):
Kernel	Title	Repro	Cause bisect	Fix bisect	Count	Last	Reported	Patched	Status
linux-4.19	INFO: task hung in lru_add_drain_all				1	76d	76d	0/1	upstream: reported on 2021/02/04 15:54

Sample crash report:

INFO: task khugepaged:1182 blocked for more than 143 seconds.
      Not tainted 5.9.0-rc6-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:khugepaged      state:D stack:29208 pid: 1182 ppid:     2 flags:0x00004000
Call Trace:
 context_switch kernel/sched/core.c:3778 [inline]
 __schedule+0xec9/0x2280 kernel/sched/core.c:4527
 schedule+0xd0/0x2a0 kernel/sched/core.c:4602
 schedule_timeout+0x1d8/0x250 kernel/time/timer.c:1855
 do_wait_for_common kernel/sched/completion.c:85 [inline]
 __wait_for_common kernel/sched/completion.c:106 [inline]
 wait_for_common kernel/sched/completion.c:117 [inline]
 wait_for_completion+0x163/0x260 kernel/sched/completion.c:138
 __flush_work+0x51f/0xac0 kernel/workqueue.c:3046
 lru_add_drain_all+0x418/0x6c0 mm/swap.c:809
 khugepaged_do_scan mm/khugepaged.c:2175 [inline]
 khugepaged+0x10e/0x5ab0 mm/khugepaged.c:2236
 kthread+0x3b5/0x4a0 kernel/kthread.c:292
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:294
INFO: task syz-executor203:8344 blocked for more than 144 seconds.
      Not tainted 5.9.0-rc6-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor203 state:D stack:28360 pid: 8344 ppid:  6871 flags:0x00000004
Call Trace:
 context_switch kernel/sched/core.c:3778 [inline]
 __schedule+0xec9/0x2280 kernel/sched/core.c:4527
 schedule+0xd0/0x2a0 kernel/sched/core.c:4602
 __lock_sock+0x13d/0x260 net/core/sock.c:2504
 lock_sock_nested+0xf1/0x110 net/core/sock.c:3043
 lock_sock include/net/sock.h:1581 [inline]
 mptcp_close+0x8d/0xc60 net/mptcp/protocol.c:1914
 inet_release+0x12e/0x280 net/ipv4/af_inet.c:431
 __sock_release+0xcd/0x280 net/socket.c:596
 sock_close+0x18/0x20 net/socket.c:1277
 __fput+0x285/0x920 fs/file_table.c:281
 task_work_run+0xdd/0x190 kernel/task_work.c:141
 tracehook_notify_resume include/linux/tracehook.h:188 [inline]
 exit_to_user_mode_loop kernel/entry/common.c:165 [inline]
 exit_to_user_mode_prepare+0x1e1/0x200 kernel/entry/common.c:192
 syscall_exit_to_user_mode+0x7e/0x2e0 kernel/entry/common.c:267
 entry_SYSCALL_64_after_hwframe+0x44/0xa9
RIP: 0033:0x408ed1
Code: Bad RIP value.
RSP: 002b:00007ffdee0068b0 EFLAGS: 00000293 ORIG_RAX: 0000000000000003
RAX: 0000000000000000 RBX: 0000000000000004 RCX: 0000000000408ed1
RDX: 0000000000000000 RSI: 0000000000000080 RDI: 0000000000000003
RBP: 000000000007f922 R08: 00000001bb1414ac R09: 00000001bb1414ac
R10: 00007ffdee0068d0 R11: 0000000000000293 R12: 00000000006dfc50
R13: 0000000000000008 R14: 00000000006dfc5c R15: 0000000000000064
INFO: task syz-executor203:8569 blocked for more than 145 seconds.
      Not tainted 5.9.0-rc6-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor203 state:D stack:27976 pid: 8569 ppid:  6868 flags:0x00004004
Call Trace:
 context_switch kernel/sched/core.c:3778 [inline]
 __schedule+0xec9/0x2280 kernel/sched/core.c:4527
 schedule+0xd0/0x2a0 kernel/sched/core.c:4602
 __lock_sock+0x13d/0x260 net/core/sock.c:2504
 lock_sock_nested+0xf1/0x110 net/core/sock.c:3043
 lock_sock include/net/sock.h:1581 [inline]
 sk_stream_wait_memory+0x775/0xe60 net/core/stream.c:145
 mptcp_sendmsg+0x53b/0x1910 net/mptcp/protocol.c:1196
 inet_sendmsg+0x99/0xe0 net/ipv4/af_inet.c:817
 sock_sendmsg_nosec net/socket.c:651 [inline]
 sock_sendmsg+0xcf/0x120 net/socket.c:671
 __sys_sendto+0x21c/0x320 net/socket.c:1992
 __do_sys_sendto net/socket.c:2004 [inline]
 __se_sys_sendto net/socket.c:2000 [inline]
 __x64_sys_sendto+0xdd/0x1b0 net/socket.c:2000
 do_syscall_64+0x2d/0x70 arch/x86/entry/common.c:46
 entry_SYSCALL_64_after_hwframe+0x44/0xa9
RIP: 0033:0x44a529
Code: Bad RIP value.
RSP: 002b:00007f9258690cd8 EFLAGS: 00000246 ORIG_RAX: 000000000000002c
RAX: ffffffffffffffda RBX: 00000000006dfc48 RCX: 000000000044a529
RDX: 00000000ffffffe7 RSI: 0000000020000100 RDI: 0000000000000003
RBP: 00000000006dfc40 R08: 0000000000000000 R09: 0000000000000000
R10: 000000000000c000 R11: 0000000000000246 R12: 00000000006dfc4c
R13: 00007ffdee00683f R14: 00007f92586919c0 R15: 0000000000000064

Showing all locks held in the system:
1 lock held by khungtaskd/1172:
 #0: ffffffff8a068440 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:5852
1 lock held by khugepaged/1182:
 #0: ffffffff8a134ba8 (lock#5){+.+.}-{3:3}, at: lru_add_drain_all+0x59/0x6c0 mm/swap.c:780
1 lock held by in:imklog/6547:
 #0: ffff88809c1d6b70 (&f->f_pos_lock){+.+.}-{3:3}, at: __fdget_pos+0xe9/0x100 fs/file.c:930
3 locks held by kworker/1:0/6852:
3 locks held by kworker/u4:4/7925:
3 locks held by kworker/0:3/8119:
1 lock held by syz-executor203/8344:
 #0: ffff8880853ff210 (&sb->s_type->i_mutex_key#13){+.+.}-{3:3}, at: inode_lock include/linux/fs.h:779 [inline]
 #0: ffff8880853ff210 (&sb->s_type->i_mutex_key#13){+.+.}-{3:3}, at: __sock_release+0x86/0x280 net/socket.c:595
2 locks held by syz-executor203/22664:
2 locks held by syz-executor203/22669:
3 locks held by syz-executor203/22667:
 #0: ffff8880ae435e98 (&rq->lock){-.-.}-{2:2}, at: rq_lock kernel/sched/sched.h:1292 [inline]
 #0: ffff8880ae435e98 (&rq->lock){-.-.}-{2:2}, at: __schedule+0x287/0x2280 kernel/sched/core.c:4445
 #1: ffff8880ae420ec8 (&per_cpu_ptr(group->pcpu, cpu)->seq){-.-.}-{0:0}, at: psi_task_switch+0x305/0x440 kernel/sched/psi.c:833
 #2: ffff88809453c2a0 (k-slock-AF_INET){+.-.}-{2:2}, at: spin_lock_bh include/linux/spinlock.h:359 [inline]
 #2: ffff88809453c2a0 (k-slock-AF_INET){+.-.}-{2:2}, at: release_sock+0x1b/0x1b0 net/core/sock.c:3056
no locks held by syz-executor203/22676.

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

NMI backtrace for cpu 1
CPU: 1 PID: 1172 Comm: khungtaskd Not tainted 5.9.0-rc6-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
 __dump_stack lib/dump_stack.c:77 [inline]
 dump_stack+0x198/0x1fd lib/dump_stack.c:118
 nmi_cpu_backtrace.cold+0x70/0xb1 lib/nmi_backtrace.c:101
 nmi_trigger_cpumask_backtrace+0x1b3/0x223 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+0xd7d/0x1000 kernel/hung_task.c:295
 kthread+0x3b5/0x4a0 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: 7925 Comm: kworker/u4:4 Not tainted 5.9.0-rc6-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Workqueue: bat_events batadv_nc_worker
RIP: 0010:__sanitizer_cov_trace_pc+0x30/0x60 kernel/kcov.c:197
Code: fe 01 00 65 8b 05 c0 76 8b 7e a9 00 01 ff 00 48 8b 34 24 74 0f f6 c4 01 74 35 8b 82 4c 14 00 00 85 c0 74 2b 8b 82 28 14 00 00 <83> f8 02 75 20 48 8b 8a 30 14 00 00 8b 92 2c 14 00 00 48 8b 01 48
RSP: 0018:ffffc9000981fc78 EFLAGS: 00000246
RAX: 0000000000000000 RBX: 0000000000000001 RCX: ffffffff881a8a48
RDX: ffff88808fae8200 RSI: ffffffff881a8760 RDI: ffff88808fae8578
RBP: 0000000000000001 R08: 0000000000000000 R09: ffffffff8d10d9e7
R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000001
R13: 0000000000000000 R14: dffffc0000000000 R15: 0000000000000145
FS:  0000000000000000(0000) GS:ffff8880ae400000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00000000200002c0 CR3: 00000000a858a000 CR4: 00000000001506f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 rcu_lock_release include/linux/rcupdate.h:246 [inline]
 rcu_read_unlock include/linux/rcupdate.h:688 [inline]
 batadv_nc_purge_orig_hash net/batman-adv/network-coding.c:411 [inline]
 batadv_nc_worker+0x790/0xe50 net/batman-adv/network-coding.c:718
 process_one_work+0x94c/0x1670 kernel/workqueue.c:2269
 worker_thread+0x64c/0x1120 kernel/workqueue.c:2415
 kthread+0x3b5/0x4a0 kernel/kthread.c:292
 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:294

Fix bisection attempts:
Manager	Time	Kernel	Commit	Syzkaller	Config	Log	Report	Syz repro	C repro
ci-upstream-net-kasan-gce	2021/04/01 06:04	net-next	04080634	1880b4a9	.config	log	report	syz	C
ci-upstream-net-kasan-gce	2020/12/05 00:55	net-next	7f356166	1880b4a9	.config	log	report	syz	C
ci-upstream-net-kasan-gce	2020/11/05 00:31	net-next	3fb6928b	1880b4a9	.config	log	report	syz	C

Crashes (21):
Manager	Time	Kernel	Commit	Syzkaller	Config	Log	Report	Syz repro	C repro	VM info	Title
ci-upstream-net-kasan-gce	2020/10/06 00:06	net-next	c2568c8c	1880b4a9	.config	log	report	syz	C
ci-upstream-net-kasan-gce	2020/10/03 16:31	net-next	678cdd49	2653fa43	.config	log	report	syz	C
ci-upstream-linux-next-kasan-gce-root	2020/06/30 23:01	linux-next	c28e58ee	917afeaa	.config	log	report	syz	C
ci-upstream-kasan-gce-selinux-root	2021/04/08 05:26	upstream	3a229812	6a81331a	.config	log	report			info	INFO: task hung in lru_add_drain_all
ci-upstream-kasan-gce-root	2021/04/02 22:35	upstream	1678e493	6a81331a	.config	log	report			info	INFO: task hung in lru_add_drain_all
ci-upstream-bpf-kasan-gce	2021/02/03 04:10	bpf	3aaf0a27	624dad51	.config	log	report			info	INFO: task hung in lru_add_drain_all
ci-upstream-bpf-kasan-gce	2021/02/01 10:01	bpf	06cc6e5d	fc9fd31e	.config	log	report			info	INFO: task hung in lru_add_drain_all
ci-upstream-bpf-next-kasan-gce	2021/01/30 23:03	bpf-next	61ca36c8	fc9fd31e	.config	log	report			info	INFO: task hung in lru_add_drain_all
ci-upstream-linux-next-kasan-gce-root	2021/02/26 19:05	linux-next	d01f2f7e	4c37c133	.config	log	report			info	INFO: task hung in lru_add_drain_all
ci-upstream-kasan-gce-root	2020/12/08 08:23	upstream	cd796ed3	51a9082e	.config	log	report			info
ci-upstream-kasan-gce	2020/07/21 11:56	upstream	4fa640dc	d88894e6	.config	log	report
ci-upstream-kasan-gce	2020/06/17 09:49	upstream	7ae77150	b9f3810b	.config	log	report
ci-upstream-bpf-next-kasan-gce	2021/01/01 18:55	bpf-next	482ec343	79264ae3	.config	log	report			info
ci-upstream-net-kasan-gce	2020/10/03 13:37	net-next	678cdd49	2653fa43	.config	log	report			info
ci-upstream-net-kasan-gce	2020/10/03 05:25	net-next	678cdd49	2653fa43	.config	log	report			info
ci-upstream-net-kasan-gce	2020/09/20 09:26	net-next	a5a3303e	53ce8104	.config	log	report			info
ci-upstream-net-kasan-gce	2020/09/20 04:03	net-next	a5a3303e	53ce8104	.config	log	report			info
ci-upstream-net-kasan-gce	2020/09/15 13:44	net-next	ed6d9b02	6989d6f6	.config	log	report			info
ci-upstream-net-kasan-gce	2020/08/07 13:19	net-next	bfdd5aaa	cb436c69	.config	log	report
ci-upstream-net-kasan-gce	2020/07/16 08:05	net-next	8635764b	f3bec699	.config	log	report
ci-upstream-linux-next-kasan-gce-root	2020/09/28 18:21	linux-next	663b07a4	6bfdbe89	.config	log	report			info