syzbot


INFO: task hung in fsnotify_mark_destroy_workfn

Status: fixed on 2020/01/16 11:28
Reported-by: syzbot+1826d52753e7c9af316e@syzkaller.appspotmail.com
Fix commit: 42a929edf567 rtc: disable uie before setting time and enable after
First crash: 2010d, last: 1822d
Fix bisection: fixed by (bisect log) :
commit 42a929edf5674aa5c9e2883dafca7eff2013729e
Author: Alexandre Belloni <alexandre.belloni@bootlin.com>
Date: Sun Oct 20 23:13:20 2019 +0000

  rtc: disable uie before setting time and enable after

  
Similar bugs (5)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: task hung in fsnotify_mark_destroy_workfn fs syz 13 2316d 2430d 10/28 fixed on 2018/09/08 03:03
upstream INFO: task hung in fsnotify_mark_destroy_workfn (2) fs 42 1883d 2283d 0/28 closed as invalid on 2019/10/23 07:21
upstream INFO: task hung in fsnotify_mark_destroy_workfn (3) fs 15 1667d 1708d 0/28 auto-closed as invalid on 2020/08/18 06:03
android-414 INFO: task hung in fsnotify_mark_destroy_workfn 9 1844d 2069d 0/1 auto-closed as invalid on 2020/03/23 16:47
linux-4.19 INFO: task hung in fsnotify_mark_destroy_workfn (2) 1 1700d 1700d 0/1 auto-closed as invalid on 2020/08/15 10:12
Fix bisection attempts (2)
Created Duration User Patch Repo Result
2020/01/15 17:52 4h10m bisect fix linux-4.19.y OK (1) job log
2019/12/16 15:32 30m bisect fix linux-4.19.y OK (0) job log log

Sample crash report:
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

Crashes (3):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2019/06/12 06:27 linux-4.19.y 768292d05361 ea2f4006 .config console log report syz ci2-linux-4-19
2019/08/06 05:03 linux-4.19.y b3060a1a313f 6affd8e8 .config console log report ci2-linux-4-19
2019/07/29 14:06 linux-4.19.y 64f4694072aa f67095ee .config console log report ci2-linux-4-19
* Struck through repros no longer work on HEAD.