INFO: task hung in rxrpc_release

From: syzbot
Date: Fri Jan 31 2020 - 13:07:18 EST


Hello,

syzbot found the following crash on:

HEAD commit: 9f68e365 Merge tag 'drm-next-2020-01-30' of git://anongit...
git tree: net-next
console output: https://syzkaller.appspot.com/x/log.txt?x=11c8c776e00000
kernel config: https://syzkaller.appspot.com/x/.config?x=95b275782b150c86
dashboard link: https://syzkaller.appspot.com/bug?extid=07d716baf0187672bc35
compiler: gcc (GCC) 9.0.0 20181231 (experimental)

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

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+07d716baf0187672bc35@xxxxxxxxxxxxxxxxxxxxxxxxx

INFO: task kworker/u4:7:432 blocked for more than 143 seconds.
Not tainted 5.5.0-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/u4:7 D26824 432 2 0x80004000
Workqueue: netns cleanup_net
Call Trace:
context_switch kernel/sched/core.c:3386 [inline]
__schedule+0x934/0x1f90 kernel/sched/core.c:4082
schedule+0xdc/0x2b0 kernel/sched/core.c:4156
schedule_timeout+0x717/0xc50 kernel/time/timer.c:1871
do_wait_for_common kernel/sched/completion.c:83 [inline]
__wait_for_common kernel/sched/completion.c:104 [inline]
wait_for_common kernel/sched/completion.c:115 [inline]
wait_for_completion+0x29c/0x440 kernel/sched/completion.c:136
flush_workqueue+0x40a/0x14c0 kernel/workqueue.c:2827
rxrpc_release_sock net/rxrpc/af_rxrpc.c:898 [inline]
rxrpc_release+0x2b2/0x5b0 net/rxrpc/af_rxrpc.c:927
__sock_release+0x1d5/0x280 net/socket.c:605
sock_release+0x18/0x20 net/socket.c:625
afs_close_socket+0x1db/0x350 fs/afs/rxrpc.c:128
afs_net_exit+0x1cd/0x320 fs/afs/main.c:151
ops_exit_list.isra.0+0xb1/0x160 net/core/net_namespace.c:172
cleanup_net+0x549/0xb10 net/core/net_namespace.c:589
process_one_work+0xa05/0x17a0 kernel/workqueue.c:2264
worker_thread+0x98/0xe40 kernel/workqueue.c:2410
kthread+0x361/0x430 kernel/kthread.c:255
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:352
INFO: task syz-executor.4:15978 blocked for more than 143 seconds.
Not tainted 5.5.0-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.4 D28240 15978 9813 0x00004004
Call Trace:
context_switch kernel/sched/core.c:3386 [inline]
__schedule+0x934/0x1f90 kernel/sched/core.c:4082
schedule+0xdc/0x2b0 kernel/sched/core.c:4156
schedule_timeout+0x717/0xc50 kernel/time/timer.c:1871
do_wait_for_common kernel/sched/completion.c:83 [inline]
__wait_for_common kernel/sched/completion.c:104 [inline]
wait_for_common kernel/sched/completion.c:115 [inline]
wait_for_completion+0x29c/0x440 kernel/sched/completion.c:136
__flush_work+0x4fe/0xa50 kernel/workqueue.c:3041
__cancel_work_timer+0x3d9/0x540 kernel/workqueue.c:3128
cancel_delayed_work_sync+0x1b/0x20 kernel/workqueue.c:3260
htable_destroy net/netfilter/xt_hashlimit.c:406 [inline]
htable_put+0x15f/0x220 net/netfilter/xt_hashlimit.c:435
hashlimit_mt_destroy+0x56/0x70 net/netfilter/xt_hashlimit.c:971
cleanup_match+0xde/0x170 net/ipv6/netfilter/ip6_tables.c:478
find_check_entry.isra.0+0x454/0x920 net/ipv4/netfilter/ip_tables.c:564
translate_table+0xcb4/0x17d0 net/ipv4/netfilter/ip_tables.c:717
do_replace net/ipv4/netfilter/ip_tables.c:1136 [inline]
do_ipt_set_ctl+0x2fe/0x4c2 net/ipv4/netfilter/ip_tables.c:1672
nf_sockopt net/netfilter/nf_sockopt.c:106 [inline]
nf_setsockopt+0x77/0xd0 net/netfilter/nf_sockopt.c:115
ip_setsockopt net/ipv4/ip_sockglue.c:1260 [inline]
ip_setsockopt+0xdf/0x100 net/ipv4/ip_sockglue.c:1240
tcp_setsockopt net/ipv4/tcp.c:3159 [inline]
tcp_setsockopt+0x8f/0xe0 net/ipv4/tcp.c:3153
sock_common_setsockopt+0x94/0xd0 net/core/sock.c:3149
__sys_setsockopt+0x261/0x4c0 net/socket.c:2130
__do_sys_setsockopt net/socket.c:2146 [inline]
__se_sys_setsockopt net/socket.c:2143 [inline]
__x64_sys_setsockopt+0xbe/0x150 net/socket.c:2143
do_syscall_64+0xfa/0x790 arch/x86/entry/common.c:294
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x45b349
Code: Bad RIP value.
RSP: 002b:00007f59d07ddc78 EFLAGS: 00000246 ORIG_RAX: 0000000000000036
RAX: ffffffffffffffda RBX: 00007f59d07de6d4 RCX: 000000000045b349
RDX: 0000000000000040 RSI: 0004000000000000 RDI: 0000000000000004
RBP: 000000000075c118 R08: 0000000000000400 R09: 0000000000000000
R10: 0000000020000e00 R11: 0000000000000246 R12: 00000000ffffffff
R13: 0000000000000a02 R14: 00000000004cb5e1 R15: 000000000075c124

Showing all locks held in the system:
4 locks held by kworker/u4:4/218:
#0: ffff8880ae837558 (&rq->lock){-.-.}, at: rq_lock kernel/sched/sched.h:1215 [inline]
#0: ffff8880ae837558 (&rq->lock){-.-.}, at: __schedule+0x232/0x1f90 kernel/sched/core.c:4030
#1: ffffffff89babf40 (rcu_read_lock){....}, at: trace_sched_stat_runtime include/trace/events/sched.h:435 [inline]
#1: ffffffff89babf40 (rcu_read_lock){....}, at: update_curr+0x2ea/0x8d0 kernel/sched/fair.c:859
#2: ffff8880ae827418 (&base->lock){-.-.}, at: lock_timer_base+0x56/0x1b0 kernel/time/timer.c:936
#3: ffffffff8ba6ac60 (&obj_hash[i].lock){-.-.}, at: debug_object_activate+0x131/0x470 lib/debugobjects.c:636
3 locks held by kworker/u4:7/432:
#0: ffff88821b044128 ((wq_completion)netns){+.+.}, at: __write_once_size include/linux/compiler.h:226 [inline]
#0: ffff88821b044128 ((wq_completion)netns){+.+.}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff88821b044128 ((wq_completion)netns){+.+.}, at: atomic64_set include/asm-generic/atomic-instrumented.h:855 [inline]
#0: ffff88821b044128 ((wq_completion)netns){+.+.}, at: atomic_long_set include/asm-generic/atomic-long.h:40 [inline]
#0: ffff88821b044128 ((wq_completion)netns){+.+.}, at: set_work_data kernel/workqueue.c:615 [inline]
#0: ffff88821b044128 ((wq_completion)netns){+.+.}, at: set_work_pool_and_clear_pending kernel/workqueue.c:642 [inline]
#0: ffff88821b044128 ((wq_completion)netns){+.+.}, at: process_one_work+0x8dd/0x17a0 kernel/workqueue.c:2235
#1: ffffc90002677dc0 (net_cleanup_work){+.+.}, at: process_one_work+0x917/0x17a0 kernel/workqueue.c:2239
#2: ffffffff8a727fc8 (pernet_ops_rwsem){++++}, at: cleanup_net+0xa1/0xb10 net/core/net_namespace.c:551
1 lock held by khungtaskd/1107:
#0: ffffffff89babf40 (rcu_read_lock){....}, at: debug_show_all_locks+0x5f/0x279 kernel/locking/lockdep.c:5333
1 lock held by khugepaged/1139:
#0: ffffffff89c50fe0 (pcpu_drain_mutex){+.+.}, at: drain_all_pages+0x4d/0x5d0 mm/page_alloc.c:2902
1 lock held by rsyslogd/9673:
#0: ffff8880879e3860 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0xee/0x110 fs/file.c:821
2 locks held by getty/9763:
#0: ffff88809dec3090 (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:340
#1: ffffc9000191f2e0 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x220/0x1bf0 drivers/tty/n_tty.c:2156
2 locks held by getty/9764:
#0: ffff88809ee49090 (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:340
#1: ffffc9000199b2e0 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x220/0x1bf0 drivers/tty/n_tty.c:2156
2 locks held by getty/9765:
#0: ffff8880a20dd090 (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:340
#1: ffffc9000197b2e0 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x220/0x1bf0 drivers/tty/n_tty.c:2156
2 locks held by getty/9766:
#0: ffff888091b8a090 (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:340
#1: ffffc9000198b2e0 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x220/0x1bf0 drivers/tty/n_tty.c:2156
2 locks held by getty/9767:
#0: ffff88809ee41090 (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:340
#1: ffffc900019ab2e0 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x220/0x1bf0 drivers/tty/n_tty.c:2156
2 locks held by getty/9768:
#0: ffff88809fd08090 (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:340
#1: ffffc900019232e0 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x220/0x1bf0 drivers/tty/n_tty.c:2156
2 locks held by getty/9769:
#0: ffff888092172090 (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:340
#1: ffffc900018fb2e0 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x220/0x1bf0 drivers/tty/n_tty.c:2156
1 lock held by syz-executor.4/15978:
#0: ffffffff8a7b80a0 (hashlimit_mutex){+.+.}, at: htable_put+0x21/0x220 net/netfilter/xt_hashlimit.c:432
2 locks held by kworker/0:3/16041:

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

NMI backtrace for cpu 1
CPU: 1 PID: 1107 Comm: khungtaskd Not tainted 5.5.0-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+0x197/0x210 lib/dump_stack.c:118
nmi_cpu_backtrace.cold+0x70/0xb2 lib/nmi_backtrace.c:101
nmi_trigger_cpumask_backtrace+0x23b/0x28b lib/nmi_backtrace.c:62
arch_trigger_cpumask_backtrace+0x14/0x20 arch/x86/kernel/apic/hw_nmi.c:38
trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:205 [inline]
watchdog+0xb11/0x10c0 kernel/hung_task.c:289
kthread+0x361/0x430 kernel/kthread.c:255
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:352
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 16041 Comm: kworker/0:3 Not tainted 5.5.0-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Workqueue: events_power_efficient htable_gc
RIP: 0010:lock_is_held_type+0x27e/0x320 kernel/locking/lockdep.c:4526
Code: 48 c1 e8 03 80 3c 10 00 0f 85 88 00 00 00 48 83 3d 0e 3a 59 08 00 74 31 48 8b 7d c0 57 9d 0f 1f 44 00 00 48 83 c4 20 44 89 e0 <5b> 41 5c 41 5d 41 5e 41 5f 5d c3 45 31 e4 e9 6e ff ff ff 41 bc 01
RSP: 0018:ffffc9000194fc38 EFLAGS: 00000282
RAX: 0000000000000000 RBX: ffff88805ad1a000 RCX: ffff88805ad1a898
RDX: dffffc0000000000 RSI: ffffffff89babec0 RDI: 0000000000000286
RBP: ffffc9000194fc60 R08: 1ffffffff169f59e R09: fffffbfff169f59f
R10: fffffbfff169f59e R11: ffffffff8b4facf7 R12: 0000000000000000
R13: ffff88805ad1a8c0 R14: ffffffff89babec0 R15: 0000000000000002
FS: 0000000000000000(0000) GS:ffff8880ae800000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f59d08209e0 CR3: 000000008df0d000 CR4: 00000000001406f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
lock_is_held include/linux/lockdep.h:361 [inline]
___might_sleep+0x205/0x2c0 kernel/sched/core.c:6765
htable_selective_cleanup+0x245/0x340 net/netfilter/xt_hashlimit.c:374
htable_gc+0x21/0xb0 net/netfilter/xt_hashlimit.c:384
process_one_work+0xa05/0x17a0 kernel/workqueue.c:2264
worker_thread+0x98/0xe40 kernel/workqueue.c:2410
kthread+0x361/0x430 kernel/kthread.c:255
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:352


---
This bug 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 syzkaller@xxxxxxxxxxxxxxxxx

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