INFO: task hung in process_one_work

47 views
Skip to first unread message

syzbot

unread,
Apr 9, 2018, 10:02:04 AM4/9/18
to syzkaller-upst...@googlegroups.com
Hello,

syzbot hit the following crash on upstream commit
3fd14cdcc05a682b03743683ce3a726898b20555 (Fri Apr 6 19:15:41 2018 +0000)
Merge tag 'mtd/for-4.17' of git://git.infradead.org/linux-mtd
syzbot dashboard link:
https://syzkaller.appspot.com/bug?extid=420725283c35bab21df3

Unfortunately, I don't have any reproducer for this crash yet.
Raw console output:
https://syzkaller.appspot.com/x/log.txt?id=4775956849885184
Kernel config:
https://syzkaller.appspot.com/x/.config?id=-5813481738265533882
compiler: gcc (GCC) 8.0.1 20180301 (experimental)
CC: [ak...@linux-foundation.org linux-...@vger.kernel.org
penguin...@I-love.SAKURA.ne.jp vegard...@oracle.com]

IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+420725...@syzkaller.appspotmail.com
It will help syzbot understand when the bug is fixed. See footer for
details.
If you forward the report, please keep this part and the footer.

INFO: task kworker/1:1:24 blocked for more than 120 seconds.
Not tainted 4.16.0+ #4
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/1:1 D17720 24 2 0x80000000
Workqueue: rcu_gp wait_rcu_exp_gp
Call Trace:
context_switch kernel/sched/core.c:2848 [inline]
__schedule+0x807/0x1e40 kernel/sched/core.c:3490
schedule+0xef/0x430 kernel/sched/core.c:3549
schedule_timeout+0x138/0x240 kernel/time/timer.c:1801
synchronize_sched_expedited_wait kernel/rcu/tree_exp.h:470 [inline]
rcu_exp_wait_wake+0x254/0x9c0 kernel/rcu/tree_exp.h:538
rcu_exp_sel_wait_wake kernel/rcu/tree_exp.h:582 [inline]
wait_rcu_exp_gp+0x83/0xc0 kernel/rcu/tree_exp.h:593
process_one_work+0xc1e/0x1b50 kernel/workqueue.c:2145
worker_thread+0x1cc/0x1440 kernel/workqueue.c:2279
kthread+0x345/0x410 kernel/kthread.c:238
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:411

Showing all locks held in the system:
2 locks held by kworker/1:1/24:
#0: 000000001f589a36 ((wq_completion)"rcu_gp"){+.+.}, at:
__write_once_size include/linux/compiler.h:215 [inline]
#0: 000000001f589a36 ((wq_completion)"rcu_gp"){+.+.}, at:
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: 000000001f589a36 ((wq_completion)"rcu_gp"){+.+.}, at: atomic64_set
include/asm-generic/atomic-instrumented.h:40 [inline]
#0: 000000001f589a36 ((wq_completion)"rcu_gp"){+.+.}, at: atomic_long_set
include/asm-generic/atomic-long.h:57 [inline]
#0: 000000001f589a36 ((wq_completion)"rcu_gp"){+.+.}, at: set_work_data
kernel/workqueue.c:617 [inline]
#0: 000000001f589a36 ((wq_completion)"rcu_gp"){+.+.}, at:
set_work_pool_and_clear_pending kernel/workqueue.c:644 [inline]
#0: 000000001f589a36 ((wq_completion)"rcu_gp"){+.+.}, at:
process_one_work+0xaef/0x1b50 kernel/workqueue.c:2116
#1: 000000001fad37d8 ((work_completion)(&rew.rew_work)){+.+.}, at:
process_one_work+0xb46/0x1b50 kernel/workqueue.c:2120
2 locks held by khungtaskd/882:
#0: 00000000d896c8ef (rcu_read_lock){....}, at:
check_hung_uninterruptible_tasks kernel/hung_task.c:175 [inline]
#0: 00000000d896c8ef (rcu_read_lock){....}, at: watchdog+0x1ff/0xf60
kernel/hung_task.c:249
#1: 000000009f6927ee (tasklist_lock){.+.+}, at:
debug_show_all_locks+0xde/0x34a kernel/locking/lockdep.c:4470
2 locks held by kworker/1:2/1966:
#0: 00000000d9d41f77 ((wq_completion)"events"){+.+.}, at:
__write_once_size include/linux/compiler.h:215 [inline]
#0: 00000000d9d41f77 ((wq_completion)"events"){+.+.}, at:
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: 00000000d9d41f77 ((wq_completion)"events"){+.+.}, at: atomic64_set
include/asm-generic/atomic-instrumented.h:40 [inline]
#0: 00000000d9d41f77 ((wq_completion)"events"){+.+.}, at: atomic_long_set
include/asm-generic/atomic-long.h:57 [inline]
#0: 00000000d9d41f77 ((wq_completion)"events"){+.+.}, at: set_work_data
kernel/workqueue.c:617 [inline]
#0: 00000000d9d41f77 ((wq_completion)"events"){+.+.}, at:
set_work_pool_and_clear_pending kernel/workqueue.c:644 [inline]
#0: 00000000d9d41f77 ((wq_completion)"events"){+.+.}, at:
process_one_work+0xaef/0x1b50 kernel/workqueue.c:2116
#1: 000000007a5d1eee (xfrm_state_gc_work){+.+.}, at:
process_one_work+0xb46/0x1b50 kernel/workqueue.c:2120
2 locks held by getty/4439:
#0: 000000004102fa04 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
#1: 000000008d75739c (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x321/0x1cc0 drivers/tty/n_tty.c:2131
2 locks held by getty/4440:
#0: 000000001677a6f2 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
#1: 0000000029959bd0 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x321/0x1cc0 drivers/tty/n_tty.c:2131
2 locks held by getty/4441:
#0: 00000000c78fba81 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
#1: 00000000158b1163 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x321/0x1cc0 drivers/tty/n_tty.c:2131
2 locks held by getty/4442:
#0: 00000000fb857431 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
#1: 00000000a0739b7f (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x321/0x1cc0 drivers/tty/n_tty.c:2131
2 locks held by getty/4443:
#0: 00000000291be71a (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
#1: 000000008358d71d (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x321/0x1cc0 drivers/tty/n_tty.c:2131
2 locks held by getty/4444:
#0: 00000000f846223a (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
#1: 00000000906269a3 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x321/0x1cc0 drivers/tty/n_tty.c:2131
2 locks held by getty/4445:
#0: 0000000061a26828 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
#1: 00000000a8b4af8c (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x321/0x1cc0 drivers/tty/n_tty.c:2131
1 lock held by syz-executor0/19397:
#0: 000000000387c4ce (event_mutex){+.+.}, at:
perf_trace_destroy+0x28/0x100 kernel/trace/trace_event_perf.c:235
1 lock held by syz-executor3/19378:
#0: 000000000387c4ce (event_mutex){+.+.}, at:
perf_trace_destroy+0x28/0x100 kernel/trace/trace_event_perf.c:235
2 locks held by syz-executor7/19387:
#0: 00000000f6414d6b (rtnl_mutex){+.+.}, at: rtnl_lock+0x17/0x20
net/core/rtnetlink.c:74
#1: 00000000c4a2a02b (rcu_sched_state.exp_mutex){+.+.}, at:
exp_funnel_lock kernel/rcu/tree_exp.h:281 [inline]
#1: 00000000c4a2a02b (rcu_sched_state.exp_mutex){+.+.}, at:
_synchronize_rcu_expedited.constprop.73+0x9dd/0xad0
kernel/rcu/tree_exp.h:616
3 locks held by syz-executor1/19393:
#0: 00000000dde0e35a (&sig->cred_guard_mutex){+.+.}, at:
SYSC_perf_event_open+0x129f/0x2fa0 kernel/events/core.c:10457
#1: 000000005f6011dd (&pmus_srcu){....}, at:
perf_event_alloc.part.91+0x103c/0x30a0 kernel/events/core.c:10018
#2: 000000000387c4ce (event_mutex){+.+.}, at: perf_trace_init+0x50/0x250
kernel/trace/trace_event_perf.c:217
1 lock held by syz-executor4/19392:
#0: 000000000387c4ce (event_mutex){+.+.}, at:
perf_trace_destroy+0x28/0x100 kernel/trace/trace_event_perf.c:235
3 locks held by syz-executor2/19395:
#0: 00000000bc21136e (&sig->cred_guard_mutex){+.+.}, at:
SYSC_perf_event_open+0x129f/0x2fa0 kernel/events/core.c:10457
#1: 000000005f6011dd (&pmus_srcu){....}, at:
perf_event_alloc.part.91+0x103c/0x30a0 kernel/events/core.c:10018
#2: 000000000387c4ce (event_mutex){+.+.}, at: perf_trace_init+0x50/0x250
kernel/trace/trace_event_perf.c:217

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

NMI backtrace for cpu 1
CPU: 1 PID: 882 Comm: khungtaskd Not tainted 4.16.0+ #4
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+0x1b9/0x294 lib/dump_stack.c:113
nmi_cpu_backtrace.cold.4+0x19/0xce lib/nmi_backtrace.c:103
nmi_trigger_cpumask_backtrace+0x151/0x192 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:138 [inline]
check_hung_task kernel/hung_task.c:132 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:190 [inline]
watchdog+0xc10/0xf60 kernel/hung_task.c:249
kthread+0x345/0x410 kernel/kthread.c:238
ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:411
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 19357 Comm: syz-executor6 Not tainted 4.16.0+ #4
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
RIP: 0010:__lock_acquire+0x72/0x5130 kernel/locking/lockdep.c:3290
RSP: 0018:ffff8801b4eb6fe0 EFLAGS: 00000082
RAX: ffffed00369d6e10 RBX: 1ffff100369d6e79 RCX: 0000000000000002
RDX: dffffc0000000000 RSI: 0000000000000000 RDI: ffffffff892f3238
RBP: ffff8801b4eb7370 R08: 0000000000000001 R09: 0000000000000001
R10: ffff88018f73a380 R11: ffff88018f73a380 R12: 0000000000000001
R13: 0000000000000000 R14: 0000000000000002 R15: ffffffff892f3238
FS: 00007fe50231b700(0000) GS:ffff8801db000000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00000000004cc720 CR3: 00000001c4583000 CR4: 00000000001406f0
DR0: 0000000020000000 DR1: 0000000020000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000600
Call Trace:
lock_acquire+0x1dc/0x520 kernel/locking/lockdep.c:3920
__raw_read_lock include/linux/rwlock_api_smp.h:149 [inline]
_raw_read_lock+0x2d/0x40 kernel/locking/spinlock.c:216
snd_pcm_stream_lock+0xaf/0xe0 sound/core/pcm_native.c:116
snd_pcm_stream_lock_irq+0x7d/0xf0 sound/core/pcm_native.c:152
__snd_pcm_lib_xfer+0x345/0x1d10 sound/core/pcm_lib.c:2162
snd_pcm_oss_write3+0xe9/0x220 sound/core/oss/pcm_oss.c:1236
io_playback_transfer+0x274/0x310 sound/core/oss/io.c:47
snd_pcm_plug_write_transfer+0x36c/0x470 sound/core/oss/pcm_plugin.c:619
snd_pcm_oss_write2+0x25c/0x460 sound/core/oss/pcm_oss.c:1365
snd_pcm_oss_write1 sound/core/oss/pcm_oss.c:1431 [inline]
snd_pcm_oss_write+0x55f/0xa20 sound/core/oss/pcm_oss.c:2774
do_loop_readv_writev fs/read_write.c:703 [inline]
do_iter_write+0x491/0x5f0 fs/read_write.c:961
vfs_writev+0x1c7/0x330 fs/read_write.c:1004
do_writev+0x112/0x2f0 fs/read_write.c:1039
SYSC_writev fs/read_write.c:1112 [inline]
SyS_writev+0x27/0x30 fs/read_write.c:1109
do_syscall_64+0x29e/0x9d0 arch/x86/entry/common.c:287
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x455259
RSP: 002b:00007fe50231ac68 EFLAGS: 00000246 ORIG_RAX: 0000000000000014
RAX: ffffffffffffffda RBX: 00007fe50231b6d4 RCX: 0000000000455259
RDX: 0000000000000007 RSI: 0000000020000580 RDI: 0000000000000014
RBP: 000000000072bea0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
R13: 00000000000006cd R14: 00000000006fd3d8 R15: 0000000000000000
Code: b3 8a b5 41 48 c7 84 24 a8 00 00 00 38 82 78 88 48 c1 e8 03 48 89 84
24 98 00 00 00 48 01 d0 48 c7 84 24 b0 00 00 00 90 d2 5a 81 <c7> 00 f1 f1
f1 f1 c7 40 04 04 f2 f2 f2 c7 40 08 f2 f2 f2 f2 c7


---
This bug is generated by a dumb bot. It may contain errors.
See https://goo.gl/tpsmEJ for details.
Direct all questions to syzk...@googlegroups.com.

syzbot will keep track of this bug report.
If you forgot to add the Reported-by tag, once the fix for this bug is
merged
into any tree, please reply to this email with:
#syz fix: exact-commit-title
To mark this as a duplicate of another syzbot report, please reply with:
#syz dup: exact-subject-of-another-report
If it's a one-off invalid bug report, please reply with:
#syz invalid
Note: if the crash happens again, it will cause creation of a new bug
report.
Note: all commands must start from beginning of the line in the email body.
To upstream this report, please reply with:
#syz upstream

syzbot

unread,
Feb 22, 2019, 5:22:15 AM2/22/19
to syzkaller-upst...@googlegroups.com
Auto-closing this bug as obsolete.
Crashes did not happen for a while, no reproducer and no activity.
Reply all
Reply to author
Forward
0 new messages