INFO: task hung in nfnetlink_rcv

INFO: task hung in nfnetlink_rcv_msg
Status: upstream: reported on 2020/01/07 16:03
Reported-by: syzbot+da20e617ce568adf13f3@syzkaller.appspotmail.com
First crash: 424d, last: 115d

Sample crash report:

INFO: task syz-executor.3:2831 blocked for more than 143 seconds.
      Not tainted 5.9.0-rc3-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
task:syz-executor.3  state:D stack:28384 pid: 2831 ppid: 24899 flags:0x00100004
Call Trace:
 context_switch kernel/sched/core.c:3778 [inline]
 __schedule+0xea9/0x2230 kernel/sched/core.c:4527
 schedule+0xd0/0x2a0 kernel/sched/core.c:4602
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:4661
 __mutex_lock_common kernel/locking/mutex.c:1033 [inline]
 __mutex_lock+0x3e2/0x10e0 kernel/locking/mutex.c:1103
 nfnl_lock net/netfilter/nfnetlink.c:63 [inline]
 nfnetlink_rcv_msg+0x912/0xea0 net/netfilter/nfnetlink.c:225
 netlink_rcv_skb+0x15a/0x430 net/netlink/af_netlink.c:2470
 nfnetlink_rcv+0x1ac/0x420 net/netfilter/nfnetlink.c:564
 netlink_unicast_kernel net/netlink/af_netlink.c:1304 [inline]
 netlink_unicast+0x533/0x7d0 net/netlink/af_netlink.c:1330
 netlink_sendmsg+0x856/0xd90 net/netlink/af_netlink.c:1919
 sock_sendmsg_nosec net/socket.c:651 [inline]
 sock_sendmsg+0xcf/0x120 net/socket.c:671
 ____sys_sendmsg+0x6e8/0x810 net/socket.c:2353
 ___sys_sendmsg+0xf3/0x170 net/socket.c:2407
 __sys_sendmsg+0xe5/0x1b0 net/socket.c:2440
 do_syscall_64+0x2d/0x70 arch/x86/entry/common.c:46
 entry_SYSCALL_64_after_hwframe+0x44/0xa9
RIP: 0033:0x45d5b9
Code: Bad RIP value.
RSP: 002b:00007f3d01edcc78 EFLAGS: 00000246 ORIG_RAX: 000000000000002e
RAX: ffffffffffffffda RBX: 0000000000029600 RCX: 000000000045d5b9
RDX: 0000000000000000 RSI: 0000000020001080 RDI: 0000000000000004
RBP: 000000000118cf80 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000118cf4c
R13: 00007ffe06c9de6f R14: 00007f3d01edd9c0 R15: 000000000118cf4c

Showing all locks held in the system:
2 locks held by systemd/1:
 #0: ffff8880988523d0 (&ei->i_mmap_sem){++++}-{3:3}, at: ext4_filemap_fault+0x7f/0xb6 fs/ext4/inode.c:6059
 #1: ffffffff89c85b80 (fs_reclaim){+.+.}-{0:0}, at: check_retry_cpuset mm/page_alloc.c:4521 [inline]
 #1: ffffffff89c85b80 (fs_reclaim){+.+.}-{0:0}, at: __alloc_pages_slowpath.constprop.0+0x1584/0x2830 mm/page_alloc.c:4725
1 lock held by khungtaskd/1170:
 #0: ffffffff89bd6a40 (rcu_read_lock){....}-{1:2}, at: debug_show_all_locks+0x53/0x260 kernel/locking/lockdep.c:5829
2 locks held by systemd-journal/3894:
 #0: ffff88809885a550 (&ei->i_mmap_sem){++++}-{3:3}, at: ext4_filemap_fault+0x7f/0xb6 fs/ext4/inode.c:6059
 #1: ffffffff89c85b80 (fs_reclaim){+.+.}-{0:0}, at: check_retry_cpuset mm/page_alloc.c:4521 [inline]
 #1: ffffffff89c85b80 (fs_reclaim){+.+.}-{0:0}, at: __alloc_pages_slowpath.constprop.0+0x1584/0x2830 mm/page_alloc.c:4725
2 locks held by systemd-timesyn/4293:
 #0: ffff888098876390 (&ei->i_mmap_sem){++++}-{3:3}, at: ext4_filemap_fault+0x7f/0xb6 fs/ext4/inode.c:6059
 #1: ffffffff89c85b80 (fs_reclaim){+.+.}-{0:0}, at: check_retry_cpuset mm/page_alloc.c:4521 [inline]
 #1: ffffffff89c85b80 (fs_reclaim){+.+.}-{0:0}, at: __alloc_pages_slowpath.constprop.0+0x1584/0x2830 mm/page_alloc.c:4725
2 locks held by in:imklog/6743:
 #0: ffff888098876390 (&ei->i_mmap_sem){++++}-{3:3}, at: ext4_filemap_fault+0x7f/0xb6 fs/ext4/inode.c:6059
 #1: ffffffff89c85b80 (fs_reclaim){+.+.}-{0:0}, at: check_retry_cpuset mm/page_alloc.c:4521 [inline]
 #1: ffffffff89c85b80 (fs_reclaim){+.+.}-{0:0}, at: __alloc_pages_slowpath.constprop.0+0x1584/0x2830 mm/page_alloc.c:4725
6 locks held by rs:main Q:Reg/6744:
2 locks held by syz-fuzzer/6839:
 #0: ffff8880862c92d0 (&ei->i_mmap_sem){++++}-{3:3}, at: ext4_filemap_fault+0x7f/0xb6 fs/ext4/inode.c:6059
 #1: ffffffff89c85b80 (fs_reclaim){+.+.}-{0:0}, at: check_retry_cpuset mm/page_alloc.c:4521 [inline]
 #1: ffffffff89c85b80 (fs_reclaim){+.+.}-{0:0}, at: __alloc_pages_slowpath.constprop.0+0x1584/0x2830 mm/page_alloc.c:4725
2 locks held by syz-fuzzer/6841:
 #0: ffff8880862c92d0 (&ei->i_mmap_sem){++++}-{3:3}, at: ext4_filemap_fault+0x7f/0xb6 fs/ext4/inode.c:6059
 #1: ffffffff89c85b80 (fs_reclaim){+.+.}-{0:0}, at: check_retry_cpuset mm/page_alloc.c:4521 [inline]
 #1: ffffffff89c85b80 (fs_reclaim){+.+.}-{0:0}, at: __alloc_pages_slowpath.constprop.0+0x1584/0x2830 mm/page_alloc.c:4725
2 locks held by syz-fuzzer/6852:
 #0: ffff8880862c92d0 (&ei->i_mmap_sem){++++}-{3:3}, at: ext4_filemap_fault+0x7f/0xb6 fs/ext4/inode.c:6059
 #1: ffffffff89c85b80 (fs_reclaim){+.+.}-{0:0}, at: check_retry_cpuset mm/page_alloc.c:4521 [inline]
 #1: ffffffff89c85b80 (fs_reclaim){+.+.}-{0:0}, at: __alloc_pages_slowpath.constprop.0+0x1584/0x2830 mm/page_alloc.c:4725
4 locks held by kworker/u4:2/29079:
 #0: ffff8880a9012138 ((wq_completion)netns){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
 #0: ffff8880a9012138 ((wq_completion)netns){+.+.}-{0:0}, at: atomic64_set include/asm-generic/atomic-instrumented.h:856 [inline]
 #0: ffff8880a9012138 ((wq_completion)netns){+.+.}-{0:0}, at: atomic_long_set include/asm-generic/atomic-long.h:41 [inline]
 #0: ffff8880a9012138 ((wq_completion)netns){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:616 [inline]
 #0: ffff8880a9012138 ((wq_completion)netns){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:643 [inline]
 #0: ffff8880a9012138 ((wq_completion)netns){+.+.}-{0:0}, at: process_one_work+0x82b/0x1670 kernel/workqueue.c:2240
 #1: ffffc9000815fda8 (net_cleanup_work){+.+.}-{0:0}, at: process_one_work+0x85f/0x1670 kernel/workqueue.c:2244
 #2: ffffffff8a7da6f0 (pernet_ops_rwsem){++++}-{3:3}, at: cleanup_net+0x9b/0xa00 net/core/net_namespace.c:565
 #3: ffffffff8d510ad8 (&table[i].mutex){+.+.}-{3:3}, at: ip_set_net_exit+0x192/0x650 net/netfilter/ipset/ip_set_core.c:2404
3 locks held by kworker/u4:5/2505:
 #0: ffff8880ae735e18 (&rq->lock){-.-.}-{2:2}, at: rq_lock kernel/sched/sched.h:1292 [inline]
 #0: ffff8880ae735e18 (&rq->lock){-.-.}-{2:2}, at: __schedule+0x270/0x2230 kernel/sched/core.c:4445
 #1: ffff8880ae720ec8 (&per_cpu_ptr(group->pcpu, cpu)->seq){-.-.}-{0:0}, at: psi_task_switch+0x2fb/0x400 kernel/sched/psi.c:833
 #2: ffff8880ae7255d8 (&base->lock){-.-.}-{2:2}, at: lock_timer_base+0x55/0x1a0 kernel/time/timer.c:947
2 locks held by syz-executor.5/2824:
 #0: ffffffff8d510ad8 (&table[i].mutex){+.+.}-{3:3}, at: nfnl_lock net/netfilter/nfnetlink.c:63 [inline]
 #0: ffffffff8d510ad8 (&table[i].mutex){+.+.}-{3:3}, at: nfnetlink_rcv_msg+0x912/0xea0 net/netfilter/nfnetlink.c:225
 #1: ffff8880ae635e18 (&rq->lock){-.-.}-{2:2}, at: rq_lock kernel/sched/sched.h:1292 [inline]
 #1: ffff8880ae635e18 (&rq->lock){-.-.}-{2:2}, at: __schedule+0x270/0x2230 kernel/sched/core.c:4445
1 lock held by syz-executor.3/2831:
 #0: ffffffff8d510ad8 (&table[i].mutex){+.+.}-{3:3}, at: nfnl_lock net/netfilter/nfnetlink.c:63 [inline]
 #0: ffffffff8d510ad8 (&table[i].mutex){+.+.}-{3:3}, at: nfnetlink_rcv_msg+0x912/0xea0 net/netfilter/nfnetlink.c:225

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

NMI backtrace for cpu 1
CPU: 1 PID: 1170 Comm: khungtaskd Not tainted 5.9.0-rc3-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: 6744 Comm: rs:main Q:Reg Not tainted 5.9.0-rc3-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:rdtsc_ordered arch/x86/include/asm/msr.h:236 [inline]
RIP: 0010:read_tsc+0x3/0x10 arch/x86/kernel/tsc.c:1094
Code: cc cc cc cc cc cc cc 8b 05 36 ca 87 09 c3 66 0f 1f 84 00 00 00 00 00 c3 0f 1f 44 00 00 66 2e 0f 1f 84 00 00 00 00 00 0f 01 f9 <66> 90 48 c1 e2 20 48 09 d0 c3 0f 1f 00 48 c7 c0 50 fb b1 8a 48 ba
RSP: 0000:ffffc90000007e60 EFLAGS: 00000046
RAX: 000000003213a36b RBX: ffffffff89b35860 RCX: 0000000000000000
RDX: 0000000000000533 RSI: ffffffff8164d813 RDI: ffffffff89b35860
RBP: ffff8880ae6208c0 R08: 0000000000000001 R09: ffff88808eb7ad60
R10: 0000000000000000 R11: 0000000000000001 R12: 00000000000779f0
R13: 0000000000000000 R14: 0000000000000000 R15: dffffc0000000000
FS:  00007f425e56d700(0000) GS:ffff8880ae600000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f54c895d560 CR3: 0000000093f32000 CR4: 00000000001506f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000600
Call Trace:
 <IRQ>
 tk_clock_read kernel/time/timekeeping.c:176 [inline]
 timekeeping_get_delta kernel/time/timekeeping.c:270 [inline]
 timekeeping_get_ns kernel/time/timekeeping.c:377 [inline]
 ktime_get+0x6a/0x120 kernel/time/timekeeping.c:762
 clockevents_program_event+0x141/0x350 kernel/time/clockevents.c:326
 tick_program_event+0xac/0x140 kernel/time/tick-oneshot.c:44
 hrtimer_interrupt+0x49b/0x930 kernel/time/hrtimer.c:1663
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1080 [inline]
 __sysvec_apic_timer_interrupt+0x142/0x5e0 arch/x86/kernel/apic/apic.c:1097
 asm_call_on_stack+0xf/0x20 arch/x86/entry/entry_64.S:706
 </IRQ>
 __run_on_irqstack arch/x86/include/asm/irq_stack.h:22 [inline]
 run_on_irqstack_cond arch/x86/include/asm/irq_stack.h:48 [inline]
 sysvec_apic_timer_interrupt+0xb2/0xf0 arch/x86/kernel/apic/apic.c:1091
 asm_sysvec_apic_timer_interrupt+0x12/0x20 arch/x86/include/asm/idtentry.h:581
RIP: 0010:arch_local_irq_restore arch/x86/include/asm/paravirt.h:770 [inline]
RIP: 0010:console_trylock_spinning kernel/printk/printk.c:1787 [inline]
RIP: 0010:vprintk_emit+0x556/0x740 kernel/printk/printk.c:2028
Code: 00 00 00 fc ff df 41 80 7c 05 00 00 0f 85 cf 01 00 00 48 83 3d 82 ad 58 08 00 0f 84 73 01 00 00 e8 2f bc 16 00 4c 89 f7 57 9d <0f> 1f 44 00 00 e8 20 bc 16 00 45 31 c9 41 b8 01 00 00 00 31 c9 68
RSP: 0000:ffffc900050975d0 EFLAGS: 00000293
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000006
RDX: ffff88808eb7a480 RSI: ffffffff815d8ed1 RDI: 0000000000000293
RBP: 0000000000000200 R08: 0000000000000001 R09: ffffffff8c5f19e7
R10: fffffbfff18be33c R11: 0000000000000001 R12: 000000000000002b
R13: 1ffffffff136c789 R14: 0000000000000293 R15: ffff8880a64ce480
 vprintk_func+0x8f/0x1a6 kernel/printk/printk_safe.c:393
 printk+0xba/0xed kernel/printk/printk.c:2078
 dump_unreclaimable_slab.cold+0xd2/0xd7 mm/slab_common.c:1006
 dump_header+0x22d/0x60f mm/oom_kill.c:465
 oom_kill_process.cold+0x10/0x15 mm/oom_kill.c:976
 out_of_memory mm/oom_kill.c:1113 [inline]
 out_of_memory+0x358/0x13f0 mm/oom_kill.c:1045
 __alloc_pages_may_oom mm/page_alloc.c:3998 [inline]
 __alloc_pages_slowpath.constprop.0+0x2132/0x2830 mm/page_alloc.c:4729
 __alloc_pages_nodemask+0x62c/0x790 mm/page_alloc.c:4901
 alloc_pages_current+0x187/0x280 mm/mempolicy.c:2275
 alloc_pages include/linux/gfp.h:545 [inline]
 __page_cache_alloc mm/filemap.c:957 [inline]
 __page_cache_alloc+0x314/0x420 mm/filemap.c:942
 pagecache_get_page+0x2a6/0xf70 mm/filemap.c:1710
 filemap_fault+0x1abd/0x2aa0 mm/filemap.c:2595
 ext4_filemap_fault+0x87/0xb6 fs/ext4/inode.c:6060
 __do_fault+0x10d/0x4d0 mm/memory.c:3463
 do_read_fault mm/memory.c:3856 [inline]
 do_fault mm/memory.c:3984 [inline]
 handle_pte_fault mm/memory.c:4224 [inline]
 __handle_mm_fault mm/memory.c:4359 [inline]
 handle_mm_fault+0x3477/0x4590 mm/memory.c:4457
 do_user_addr_fault+0x598/0xbf0 arch/x86/mm/fault.c:1294
 handle_page_fault arch/x86/mm/fault.c:1351 [inline]
 exc_page_fault+0xa8/0x190 arch/x86/mm/fault.c:1404
 asm_exc_page_fault+0x1e/0x30 arch/x86/include/asm/idtentry.h:538
RIP: 0033:0x555def8efffe
Code: Bad RIP value.
RSP: 002b:00007f425e56cac0 EFLAGS: 00010202
RAX: 0000000000000000 RBX: 0000555defb50bec RCX: 0000000000000000
RDX: 0000555df092e200 RSI: 0000555df09340d0 RDI: 0000000000000001
RBP: 0000555df092e220 R08: 0000000000000065 R09: 0000000000000008
R10: 0000555defb49280 R11: 0000000000000000 R12: 0000555df09353d0
R13: 0000000000000000 R14: 00007f425402a0f0 R15: 0000555df092e250

Crashes (30):
Manager	Time	Kernel	Commit	Syzkaller	Config	Log	Report	VM info
ci-upstream-kasan-gce-selinux-root	2020/09/01 10:54	upstream	b51594df	d5a3ae1f	.config	log	report
ci-upstream-kasan-gce	2020/07/09 19:26	upstream	0bddd227	bc238812	.config	log	report
ci-upstream-kasan-gce	2020/05/04 21:18	upstream	9851a0de	9941337c	.config	log	report
ci-upstream-kasan-gce	2020/05/04 16:38	upstream	0e698dfa	58ae5e18	.config	log	report
ci-upstream-kasan-gce-selinux-root	2020/03/02 20:38	upstream	63623fd4	c88c7b75	.config	log	report
ci-upstream-kasan-gce-smack-root	2020/02/20 07:19	upstream	ca7e1fd1	81230308	.config	log	report
ci-upstream-kasan-gce	2020/01/17 13:35	upstream	f4353c3e	3de7aabb	.config	log	report
ci-upstream-kasan-gce-smack-root	2020/01/17 13:13	upstream	f4353c3e	3de7aabb	.config	log	report
ci-upstream-kasan-gce-selinux-root	2020/01/17 13:09	upstream	f4353c3e	3de7aabb	.config	log	report
ci-upstream-kasan-gce-selinux-root	2020/01/13 08:57	upstream	040a3c33	53faa9fe	.config	log	report
ci-upstream-kasan-gce	2020/01/08 04:31	upstream	ae608821	6738e0b3	.config	log	report
ci-upstream-kasan-gce-selinux-root	2020/01/07 12:42	upstream	ae608821	1bcd407e	.config	log	report
ci-upstream-kasan-gce-root	2020/01/07 12:20	upstream	ae608821	1bcd407e	.config	log	report
ci-upstream-kasan-gce-386	2020/11/11 10:48	upstream	eccc8767	cca87986	.config	log	report	info
ci-upstream-kasan-gce-386	2020/05/19 22:30	upstream	642b151f	6d882fd2	.config	log	report
ci-upstream-kasan-gce-386	2020/03/14 21:23	upstream	69a4d0ba	749688d2	.config	log	report
ci-upstream-kasan-gce-386	2020/01/07 16:26	upstream	ae608821	1bcd407e	.config	log	report
ci-upstream-kasan-gce-386	2020/01/07 12:25	upstream	ae608821	1bcd407e	.config	log	report
ci-upstream-net-this-kasan-gce	2020/01/17 13:14	net	93ad0f96	3de7aabb	.config	log	report
ci-upstream-net-this-kasan-gce	2020/01/17 13:11	net	93ad0f96	3de7aabb	.config	log	report
ci-upstream-net-this-kasan-gce	2020/01/07 13:08	net	c101fffc	1bcd407e	.config	log	report
ci-upstream-net-this-kasan-gce	2020/01/07 12:59	net	c101fffc	1bcd407e	.config	log	report
ci-upstream-net-this-kasan-gce	2020/01/07 11:29	net	c101fffc	1bcd407e	.config	log	report
ci-upstream-net-this-kasan-gce	2020/01/07 11:28	net	c101fffc	1bcd407e	.config	log	report
ci-upstream-net-kasan-gce	2020/03/28 04:42	net-next	8a8f8281	831e9a81	.config	log	report
ci-upstream-net-kasan-gce	2020/01/17 13:38	net-next	6bc80380	3de7aabb	.config	log	report
ci-upstream-net-kasan-gce	2020/01/07 11:23	net-next	1b935183	1bcd407e	.config	log	report
ci-upstream-linux-next-kasan-gce-root	2020/01/07 12:26	linux-next	26467385	1bcd407e	.config	log	report
ci-upstream-linux-next-kasan-gce-root	2020/01/07 12:24	linux-next	26467385	1bcd407e	.config	log	report
ci-upstream-linux-next-kasan-gce-root	2020/01/07 12:04	linux-next	26467385	1bcd407e	.config	log	report