INFO: task hung in fsnotify_mark_destroy_workfn
29 views
Skip to first unread message
syzbot
Jun 12, 2019, 3:28:06 AM6/12/19
to syzkaller...@googlegroups.com
Hello,
syzbot found the following crash on:
HEAD commit: 768292d0 Linux 4.19.50
git tree: linux-4.19.y
console output: https://syzkaller.appspot.com/x/log.txt?x=16e46f2ea00000
kernel config: https://syzkaller.appspot.com/x/.config?x=51f16e11efb124be
dashboard link: https://syzkaller.appspot.com/bug?extid=1826d52753e7c9af316e
compiler: gcc (GCC) 9.0.0 20181231 (experimental)
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=12b7eecaa00000
IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+1826d5...@syzkaller.appspotmail.com
INFO: task kworker/u4:2:30 blocked for more than 140 seconds.
Not tainted 4.19.50 #22
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/u4:2 D25232 30 2 0x80000000
Workqueue: events_unbound fsnotify_mark_destroy_workfn
Call Trace:
context_switch kernel/sched/core.c:2826 [inline]
__schedule+0x80d/0x1c70 kernel/sched/core.c:3474
schedule+0x92/0x1c0 kernel/sched/core.c:3518
schedule_timeout+0x8c8/0xfc0 kernel/time/timer.c:1780
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
__synchronize_srcu+0x12e/0x210 kernel/rcu/srcutree.c:936
synchronize_srcu+0x2dc/0x3e8 kernel/rcu/srcutree.c:1014
fsnotify_mark_destroy_workfn+0x110/0x3b0 fs/notify/mark.c:795
process_one_work+0x989/0x1750 kernel/workqueue.c:2153
worker_thread+0x98/0xe40 kernel/workqueue.c:2296
kthread+0x354/0x420 kernel/kthread.c:246
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415
Showing all locks held in the system:
2 locks held by kworker/u4:2/30:
#0: 000000003ba326e9 ((wq_completion)"events_unbound"){+.+.}, at:
__write_once_size include/linux/compiler.h:220 [inline]
#0: 000000003ba326e9 ((wq_completion)"events_unbound"){+.+.}, at:
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: 000000003ba326e9 ((wq_completion)"events_unbound"){+.+.}, at:
atomic64_set include/asm-generic/atomic-instrumented.h:40 [inline]
#0: 000000003ba326e9 ((wq_completion)"events_unbound"){+.+.}, at:
atomic_long_set include/asm-generic/atomic-long.h:59 [inline]
#0: 000000003ba326e9 ((wq_completion)"events_unbound"){+.+.}, at:
set_work_data kernel/workqueue.c:617 [inline]
#0: 000000003ba326e9 ((wq_completion)"events_unbound"){+.+.}, at:
set_work_pool_and_clear_pending kernel/workqueue.c:644 [inline]
#0: 000000003ba326e9 ((wq_completion)"events_unbound"){+.+.}, at:
process_one_work+0x87e/0x1750 kernel/workqueue.c:2124
#1: 00000000aafd8475 ((reaper_work).work){+.+.}, at:
process_one_work+0x8b4/0x1750 kernel/workqueue.c:2128
1 lock held by khungtaskd/1029:
#0: 0000000038fcbee6 (rcu_read_lock){....}, at:
debug_show_all_locks+0x5f/0x27e kernel/locking/lockdep.c:4435
3 locks held by kworker/1:2/3214:
1 lock held by rsyslogd/7875:
#0: 0000000007ed6743 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0xee/0x110
fs/file.c:767
2 locks held by getty/7997:
#0: 00000000d4a87744 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 0000000088e9178c (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/7998:
#0: 000000002f4c4d6e (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 00000000bd667851 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/7999:
#0: 0000000023749852 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 000000003a918e80 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/8000:
#0: 00000000635f5376 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 00000000d3d77d32 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/8001:
#0: 0000000086f21582 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 00000000d69edbb8 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/8002:
#0: 0000000039da8a50 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 00000000373226c4 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/8003:
#0: 000000002750c734 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 0000000090184871 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
1 lock held by syz-executor.0/8854:
#0: 0000000006496e6f (&rtc->ops_lock){+.+.}, at: rtc_dev_ioctl+0xf3/0x980
drivers/rtc/rtc-dev.c:219
=============================================
NMI backtrace for cpu 0
CPU: 0 PID: 1029 Comm: khungtaskd Not tainted 4.19.50 #22
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+0x172/0x1f0 lib/dump_stack.c:113
nmi_cpu_backtrace.cold+0x63/0xa4 lib/nmi_backtrace.c:101
nmi_trigger_cpumask_backtrace+0x1b0/0x1f8 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:203 [inline]
watchdog+0x9df/0xee0 kernel/hung_task.c:287
kthread+0x354/0x420 kernel/kthread.c:246
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 3214 Comm: kworker/1:2 Not tainted 4.19.50 #22
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Workqueue: events rtc_timer_do_work
RIP: 0010:__lock_acquire+0x48b/0x48f0 kernel/locking/lockdep.c:3366
Code: 48 ba 00 00 00 00 00 fc ff df 0f b6 0c 11 48 89 fa 83 e2 07 83 c2 03
38 ca 7c 08 84 c9 0f 85 fb 2b 00 00 41 8b 96 6c 08 00 00 <49> 8d 7a 24 31
c9 85 d2 48 89 fa 0f 95 c1 c1 e3 0f 01 c1 41 c1 e4
RSP: 0018:ffff88809bd677c0 EFLAGS: 00000046
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
RDX: 0000000000000000 RSI: 1ffff110137a81e6 RDI: ffff88809bd40eac
RBP: ffff88809bd67990 R08: 0000000000000001 R09: 0000000000000003
R10: ffff88809bd40f38 R11: 00000000000005b7 R12: 0000000000000000
R13: 0000000000000001 R14: ffff88809bd40640 R15: ffff88809bd40f50
FS: 0000000000000000(0000) GS:ffff8880ae900000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f2b68fd5330 CR3: 00000000917a1000 CR4: 00000000001406e0
Call Trace:
lock_acquire+0x16f/0x3f0 kernel/locking/lockdep.c:3900
__raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
_raw_spin_lock_irqsave+0x95/0xcd kernel/locking/spinlock.c:152
__wake_up_common_lock+0xc7/0x190 kernel/sched/wait.c:120
__wake_up+0xe/0x10 kernel/sched/wait.c:145
rtc_handle_legacy_irq+0x8f/0xd0 drivers/rtc/interface.c:610
rtc_uie_update_irq+0x20/0x30 drivers/rtc/interface.c:637
rtc_timer_do_work+0x2c8/0xef0 drivers/rtc/interface.c:918
process_one_work+0x989/0x1750 kernel/workqueue.c:2153
worker_thread+0x98/0xe40 kernel/workqueue.c:2296
kthread+0x354/0x420 kernel/kthread.c:246
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415
---
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 syzk...@googlegroups.com.
syzbot will keep track of this bug report. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
syzbot can test patches for this bug, for details see:
https://goo.gl/tpsmEJ#testing-patches
syzbot found the following crash on:
HEAD commit: 768292d0 Linux 4.19.50
git tree: linux-4.19.y
console output: https://syzkaller.appspot.com/x/log.txt?x=16e46f2ea00000
kernel config: https://syzkaller.appspot.com/x/.config?x=51f16e11efb124be
dashboard link: https://syzkaller.appspot.com/bug?extid=1826d52753e7c9af316e
compiler: gcc (GCC) 9.0.0 20181231 (experimental)
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=12b7eecaa00000
IMPORTANT: if you fix the bug, please add the following tag to the commit:
Reported-by: syzbot+1826d5...@syzkaller.appspotmail.com
INFO: task kworker/u4:2:30 blocked for more than 140 seconds.
Not tainted 4.19.50 #22
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/u4:2 D25232 30 2 0x80000000
Workqueue: events_unbound fsnotify_mark_destroy_workfn
Call Trace:
context_switch kernel/sched/core.c:2826 [inline]
__schedule+0x80d/0x1c70 kernel/sched/core.c:3474
schedule+0x92/0x1c0 kernel/sched/core.c:3518
schedule_timeout+0x8c8/0xfc0 kernel/time/timer.c:1780
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
__synchronize_srcu+0x12e/0x210 kernel/rcu/srcutree.c:936
synchronize_srcu+0x2dc/0x3e8 kernel/rcu/srcutree.c:1014
fsnotify_mark_destroy_workfn+0x110/0x3b0 fs/notify/mark.c:795
process_one_work+0x989/0x1750 kernel/workqueue.c:2153
worker_thread+0x98/0xe40 kernel/workqueue.c:2296
kthread+0x354/0x420 kernel/kthread.c:246
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415
Showing all locks held in the system:
2 locks held by kworker/u4:2/30:
#0: 000000003ba326e9 ((wq_completion)"events_unbound"){+.+.}, at:
__write_once_size include/linux/compiler.h:220 [inline]
#0: 000000003ba326e9 ((wq_completion)"events_unbound"){+.+.}, at:
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: 000000003ba326e9 ((wq_completion)"events_unbound"){+.+.}, at:
atomic64_set include/asm-generic/atomic-instrumented.h:40 [inline]
#0: 000000003ba326e9 ((wq_completion)"events_unbound"){+.+.}, at:
atomic_long_set include/asm-generic/atomic-long.h:59 [inline]
#0: 000000003ba326e9 ((wq_completion)"events_unbound"){+.+.}, at:
set_work_data kernel/workqueue.c:617 [inline]
#0: 000000003ba326e9 ((wq_completion)"events_unbound"){+.+.}, at:
set_work_pool_and_clear_pending kernel/workqueue.c:644 [inline]
#0: 000000003ba326e9 ((wq_completion)"events_unbound"){+.+.}, at:
process_one_work+0x87e/0x1750 kernel/workqueue.c:2124
#1: 00000000aafd8475 ((reaper_work).work){+.+.}, at:
process_one_work+0x8b4/0x1750 kernel/workqueue.c:2128
1 lock held by khungtaskd/1029:
#0: 0000000038fcbee6 (rcu_read_lock){....}, at:
debug_show_all_locks+0x5f/0x27e kernel/locking/lockdep.c:4435
3 locks held by kworker/1:2/3214:
1 lock held by rsyslogd/7875:
#0: 0000000007ed6743 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0xee/0x110
fs/file.c:767
2 locks held by getty/7997:
#0: 00000000d4a87744 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 0000000088e9178c (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/7998:
#0: 000000002f4c4d6e (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 00000000bd667851 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/7999:
#0: 0000000023749852 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 000000003a918e80 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/8000:
#0: 00000000635f5376 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 00000000d3d77d32 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/8001:
#0: 0000000086f21582 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 00000000d69edbb8 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/8002:
#0: 0000000039da8a50 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 00000000373226c4 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
2 locks held by getty/8003:
#0: 000000002750c734 (&tty->ldisc_sem){++++}, at:
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:363
#1: 0000000090184871 (&ldata->atomic_read_lock){+.+.}, at:
n_tty_read+0x232/0x1b30 drivers/tty/n_tty.c:2154
1 lock held by syz-executor.0/8854:
#0: 0000000006496e6f (&rtc->ops_lock){+.+.}, at: rtc_dev_ioctl+0xf3/0x980
drivers/rtc/rtc-dev.c:219
=============================================
NMI backtrace for cpu 0
CPU: 0 PID: 1029 Comm: khungtaskd Not tainted 4.19.50 #22
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+0x172/0x1f0 lib/dump_stack.c:113
nmi_cpu_backtrace.cold+0x63/0xa4 lib/nmi_backtrace.c:101
nmi_trigger_cpumask_backtrace+0x1b0/0x1f8 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:203 [inline]
watchdog+0x9df/0xee0 kernel/hung_task.c:287
kthread+0x354/0x420 kernel/kthread.c:246
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 3214 Comm: kworker/1:2 Not tainted 4.19.50 #22
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS
Google 01/01/2011
Workqueue: events rtc_timer_do_work
RIP: 0010:__lock_acquire+0x48b/0x48f0 kernel/locking/lockdep.c:3366
Code: 48 ba 00 00 00 00 00 fc ff df 0f b6 0c 11 48 89 fa 83 e2 07 83 c2 03
38 ca 7c 08 84 c9 0f 85 fb 2b 00 00 41 8b 96 6c 08 00 00 <49> 8d 7a 24 31
c9 85 d2 48 89 fa 0f 95 c1 c1 e3 0f 01 c1 41 c1 e4
RSP: 0018:ffff88809bd677c0 EFLAGS: 00000046
RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
RDX: 0000000000000000 RSI: 1ffff110137a81e6 RDI: ffff88809bd40eac
RBP: ffff88809bd67990 R08: 0000000000000001 R09: 0000000000000003
R10: ffff88809bd40f38 R11: 00000000000005b7 R12: 0000000000000000
R13: 0000000000000001 R14: ffff88809bd40640 R15: ffff88809bd40f50
FS: 0000000000000000(0000) GS:ffff8880ae900000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f2b68fd5330 CR3: 00000000917a1000 CR4: 00000000001406e0
Call Trace:
lock_acquire+0x16f/0x3f0 kernel/locking/lockdep.c:3900
__raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
_raw_spin_lock_irqsave+0x95/0xcd kernel/locking/spinlock.c:152
__wake_up_common_lock+0xc7/0x190 kernel/sched/wait.c:120
__wake_up+0xe/0x10 kernel/sched/wait.c:145
rtc_handle_legacy_irq+0x8f/0xd0 drivers/rtc/interface.c:610
rtc_uie_update_irq+0x20/0x30 drivers/rtc/interface.c:637
rtc_timer_do_work+0x2c8/0xef0 drivers/rtc/interface.c:918
process_one_work+0x989/0x1750 kernel/workqueue.c:2153
worker_thread+0x98/0xe40 kernel/workqueue.c:2296
kthread+0x354/0x420 kernel/kthread.c:246
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415
---
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 syzk...@googlegroups.com.
syzbot will keep track of this bug report. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
syzbot can test patches for this bug, for details see:
https://goo.gl/tpsmEJ#testing-patches
syzbot
Jan 15, 2020, 5:03:03 PM1/15/20
to syzkaller...@googlegroups.com
syzbot suspects this bug was fixed by commit:
commit 42a929edf5674aa5c9e2883dafca7eff2013729e
Author: Alexandre Belloni <alexandr...@bootlin.com>
Date: Sun Oct 20 23:13:20 2019 +0000
rtc: disable uie before setting time and enable after
bisection log: https://syzkaller.appspot.com/x/bisect.txt?x=11d62b3ee00000
start commit: 768292d0 Linux 4.19.50
git tree: linux-4.19.y
If the result looks correct, please mark the bug fixed by replying with:
#syz fix: rtc: disable uie before setting time and enable after
For information about bisection process see: https://goo.gl/tpsmEJ#bisection
commit 42a929edf5674aa5c9e2883dafca7eff2013729e
Author: Alexandre Belloni <alexandr...@bootlin.com>
Date: Sun Oct 20 23:13:20 2019 +0000
rtc: disable uie before setting time and enable after
bisection log: https://syzkaller.appspot.com/x/bisect.txt?x=11d62b3ee00000
start commit: 768292d0 Linux 4.19.50
git tree: linux-4.19.y
kernel config: https://syzkaller.appspot.com/x/.config?x=51f16e11efb124be
dashboard link: https://syzkaller.appspot.com/bug?extid=1826d52753e7c9af316e
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=12b7eecaa00000
dashboard link: https://syzkaller.appspot.com/bug?extid=1826d52753e7c9af316e
If the result looks correct, please mark the bug fixed by replying with:
#syz fix: rtc: disable uie before setting time and enable after
For information about bisection process see: https://goo.gl/tpsmEJ#bisection
Reply all
Reply to author
Forward
0 new messages