syzbot


INFO: task hung in fsnotify_connector_destroy_workfn

Status: closed as dup on 2018/07/18 14:05
Subsystems: fs
[Documentation on labels]
Reported-by: syzbot+4417a2fa149da3802a74@syzkaller.appspotmail.com
First crash: 2422d, last: 2343d
Duplicate of
Title Repro Cause bisect Fix bisect Count Last Reported
INFO: task hung in fsnotify_mark_destroy_workfn fs syz 13 2325d 2439d
Discussions (1)
Title Replies (including bot) Last reply
INFO: task hung in fsnotify_connector_destroy_workfn 0 (1) 2018/05/05 15:47
Similar bugs (4)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
linux-4.19 INFO: task hung in fsnotify_connector_destroy_workfn 1 2070d 2070d 0/1 auto-closed as invalid on 2019/10/19 09:18
android-414 INFO: task hung in fsnotify_connector_destroy_workfn 6 1859d 2078d 0/1 auto-closed as invalid on 2020/03/18 16:55
upstream INFO: task hung in fsnotify_connector_destroy_workfn (2) fs syz error error 62 1656d 2289d 0/28 auto-obsoleted due to no activity on 2022/09/20 11:34
linux-4.19 INFO: task hung in fsnotify_connector_destroy_workfn (2) 2 1691d 1709d 0/1 auto-closed as invalid on 2020/09/02 10:35

Sample crash report:
binder: 31267:31267 transaction failed 29189/-22, size 24-8 line 2852
binder: 31268:31268 transaction failed 29189/-22, size 24-8 line 2852
binder: 31271:31271 transaction failed 29189/-22, size 24-8 line 2852
binder: 31273:31273 transaction failed 29189/-22, size 24-8 line 2852
binder: undelivered TRANSACTION_ERROR: 29189
INFO: task kworker/u4:1:23 blocked for more than 140 seconds.
      Not tainted 4.18.0-rc5+ #150
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/u4:1    D20248    23      2 0x80000000
Workqueue: events_unbound fsnotify_connector_destroy_workfn
binder: 31278:31278 transaction failed 29189/-22, size 24-8 line 2852
Call Trace:
 context_switch kernel/sched/core.c:2853 [inline]
 __schedule+0x87c/0x1ed0 kernel/sched/core.c:3501
binder: 31280:31280 transaction failed 29189/-22, size 24-8 line 2852
binder: 31281:31281 transaction failed 29189/-22, size 24-8 line 2852
 schedule+0xfb/0x450 kernel/sched/core.c:3545
binder: 31276:31276 transaction failed 29189/-22, size 24-8 line 2852
binder: 31283:31283 transaction failed 29189/-22, size 24-8 line 2852
binder: 31284:31284 transaction failed 29189/-22, size 24-8 line 2852
 schedule_timeout+0x1cc/0x260 kernel/time/timer.c:1777
 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+0x430/0x8d0 kernel/sched/completion.c:136
 __synchronize_srcu+0x189/0x240 kernel/rcu/srcutree.c:928
binder: 31287:31287 transaction failed 29189/-22, size 24-8 line 2852
 synchronize_srcu_expedited kernel/rcu/srcutree.c:953 [inline]
 synchronize_srcu+0x335/0x56f kernel/rcu/srcutree.c:1004
binder: 31289:31289 transaction failed 29189/-22, size 24-8 line 2852
binder: 31291:31291 transaction failed 29189/-22, size 24-8 line 2852
 fsnotify_connector_destroy_workfn+0x44/0xa0 fs/notify/mark.c:156
 process_one_work+0xc73/0x1ba0 kernel/workqueue.c:2153
binder: 31292:31292 transaction failed 29189/-22, size 24-8 line 2852
binder: 31294:31294 transaction failed 29189/-22, size 24-8 line 2852
binder: 31295:31295 transaction failed 29189/-22, size 24-8 line 2852
binder: 31277:31277 transaction failed 29189/-22, size 24-8 line 2852
 worker_thread+0x189/0x13c0 kernel/workqueue.c:2296
binder: 31297:31297 transaction failed 29189/-22, size 24-8 line 2852
binder: 31300:31300 transaction failed 29189/-22, size 24-8 line 2852
binder: 31301:31301 transaction failed 29189/-22, size 24-8 line 2852
binder: 31302:31302 transaction failed 29189/-22, size 24-8 line 2852
 kthread+0x345/0x410 kernel/kthread.c:246
 ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:412
INFO: task kworker/u4:0:4704 blocked for more than 140 seconds.
binder: 31304:31304 transaction failed 29189/-22, size 24-8 line 2852
      Not tainted 4.18.0-rc5+ #150
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/u4:0    D22392  4704      2 0x80000000
Workqueue: events_unbound fsnotify_mark_destroy_workfn
binder: 31305:31305 transaction failed 29189/-22, size 24-8 line 2852
Call Trace:
binder: 31307:31307 transaction failed 29189/-22, size 24-8 line 2852
 context_switch kernel/sched/core.c:2853 [inline]
 __schedule+0x87c/0x1ed0 kernel/sched/core.c:3501
 schedule+0xfb/0x450 kernel/sched/core.c:3545
binder: 31286:31286 transaction failed 29189/-22, size 24-8 line 2852
 schedule_timeout+0x1cc/0x260 kernel/time/timer.c:1777
binder: 31309:31309 transaction failed 29189/-22, size 24-8 line 2852
 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+0x430/0x8d0 kernel/sched/completion.c:136
binder: 31312:31312 transaction failed 29189/-22, size 24-8 line 2852
 __synchronize_srcu+0x189/0x240 kernel/rcu/srcutree.c:928
binder: 31314:31314 transaction failed 29189/-22, size 24-8 line 2852
binder: 31316:31316 transaction failed 29189/-22, size 24-8 line 2852
 synchronize_srcu+0x41c/0x56f kernel/rcu/srcutree.c:1006
 fsnotify_mark_destroy_workfn+0x1be/0x550 fs/notify/mark.c:765
binder: 31319:31319 transaction failed 29189/-22, size 24-8 line 2852
binder: 31320:31320 transaction failed 29189/-22, size 24-8 line 2852
 process_one_work+0xc73/0x1ba0 kernel/workqueue.c:2153
binder: 31321:31321 transaction failed 29189/-22, size 24-8 line 2852
binder: 31322:31322 transaction failed 29189/-22, size 24-8 line 2852
binder: 31324:31324 transaction failed 29189/-22, size 24-8 line 2852
 worker_thread+0x189/0x13c0 kernel/workqueue.c:2296
binder: 31327:31327 transaction failed 29189/-22, size 24-8 line 2852
binder: 31326:31326 transaction failed 29189/-22, size 24-8 line 2852
 kthread+0x345/0x410 kernel/kthread.c:246
binder: 31310:31310 transaction failed 29189/-22, size 24-8 line 2852
 ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:412

Showing all locks held in the system:
binder: 31329:31329 transaction failed 29189/-22, size 24-8 line 2852
2 locks held by kworker/u4:1/23:
binder: 31315:31315 transaction failed 29189/-22, size 24-8 line 2852
 #0: 
binder: 31330:31330 transaction failed 29189/-22, size 24-8 line 2852
00000000b53ad703 ((wq_completion)"events_unbound"){+.+.}, at: __write_once_size include/linux/compiler.h:215 [inline]
00000000b53ad703 ((wq_completion)"events_unbound"){+.+.}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
00000000b53ad703 ((wq_completion)"events_unbound"){+.+.}, at: atomic64_set include/asm-generic/atomic-instrumented.h:40 [inline]
00000000b53ad703 ((wq_completion)"events_unbound"){+.+.}, at: atomic_long_set include/asm-generic/atomic-long.h:59 [inline]
00000000b53ad703 ((wq_completion)"events_unbound"){+.+.}, at: set_work_data kernel/workqueue.c:617 [inline]
00000000b53ad703 ((wq_completion)"events_unbound"){+.+.}, at: set_work_pool_and_clear_pending kernel/workqueue.c:644 [inline]
00000000b53ad703 ((wq_completion)"events_unbound"){+.+.}, at: process_one_work+0xb44/0x1ba0 kernel/workqueue.c:2124
 #1: 
binder: 31333:31333 transaction failed 29189/-22, size 24-8 line 2852
000000007622eab5 (connector_reaper_work){+.+.}, at: process_one_work+0xb9b/0x1ba0 kernel/workqueue.c:2128
2 locks held by kworker/0:1/26:
1 lock held by khungtaskd/901:
 #0: 
binder: 31332:31332 transaction failed 29189/-22, size 24-8 line 2852
000000002dcfa648 (rcu_read_lock){....}, at: debug_show_all_locks+0xd0/0x428 kernel/locking/lockdep.c:4461
1 lock held by rsyslogd/4457:
binder: 31317:31317 transaction failed 29189/-22, size 24-8 line 2852
 #0: 00000000e4514a94 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0x1bb/0x200 fs/file.c:766
binder: 31334:31334 transaction failed 29189/-22, size 24-8 line 2852
2 locks held by getty/4547:
 #0: 00000000f634cb31 (
binder: 31336:31336 transaction failed 29189/-22, size 24-8 line 2852
&tty->ldisc_sem){++++}, at: ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
 #1: 00000000e2e2cd32 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/4548:
 #0: 00000000e750bbbf (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
 #1: 00000000379a8897 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/4549:
 #0: 00000000772659a5 (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
binder: 31341:31341 transaction failed 29189/-22, size 24-8 line 2852
 #1: 0000000085409967 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/4550:
 #0: 000000002d29de56 (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
 #1: 00000000bfd94bf1 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/4551:
 #0: 00000000b204ca6e (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
 #1: 000000000ce8223b (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
binder: 31343:31343 transaction failed 29189/-22, size 24-8 line 2852
2 locks held by getty/4552:
 #0: 00000000493238c4 (&tty->ldisc_sem){++++}, at: ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
binder: 31344:31344 transaction failed 29189/-22, size 24-8 line 2852
 #1: 000000008ed87d2c (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by getty/4553:
 #0: 000000003564fd95 (
binder: 31345:31345 transaction failed 29189/-22, size 24-8 line 2852
&tty->ldisc_sem){++++}, at: ldsem_down_read+0x37/0x40 drivers/tty/tty_ldsem.c:365
binder: 31346:31346 transaction failed 29189/-22, size 24-8 line 2852
 #1: 00000000f2c5ea37 (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x335/0x1ce0 drivers/tty/n_tty.c:2140
2 locks held by kworker/u4:0/4704:
binder: 31347:31347 transaction failed 29189/-22, size 24-8 line 2852
 #0: 00000000b53ad703 ((wq_completion)"events_unbound"){+.+.}, at: __write_once_size include/linux/compiler.h:215 [inline]
 #0: 00000000b53ad703 ((wq_completion)"events_unbound"){+.+.}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
 #0: 00000000b53ad703 ((wq_completion)"events_unbound"){+.+.}, at: atomic64_set include/asm-generic/atomic-instrumented.h:40 [inline]
 #0: 00000000b53ad703 ((wq_completion)"events_unbound"){+.+.}, at: atomic_long_set include/asm-generic/atomic-long.h:59 [inline]
 #0: 00000000b53ad703 ((wq_completion)"events_unbound"){+.+.}, at: set_work_data kernel/workqueue.c:617 [inline]
 #0: 00000000b53ad703 ((wq_completion)"events_unbound"){+.+.}, at: set_work_pool_and_clear_pending kernel/workqueue.c:644 [inline]
 #0: 00000000b53ad703 ((wq_completion)"events_unbound"){+.+.}, at: process_one_work+0xb44/0x1ba0 kernel/workqueue.c:2124
 #1: 00000000e597247a ((reaper_work).work){+.+.}, at: process_one_work+0xb9b/0x1ba0 kernel/workqueue.c:2128
1 lock held by udevd/31331:

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

NMI backtrace for cpu 0
CPU: 0 PID: 901 Comm: khungtaskd Not tainted 4.18.0-rc5+ #150
binder: 31350:31350 transaction failed 29189/-22, size 24-8 line 2852
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+0x1c9/0x2b4 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
binder: 31351:31351 transaction failed 29189/-22, size 24-8 line 2852
 trigger_all_cpu_backtrace include/linux/nmi.h:138 [inline]
 check_hung_uninterruptible_tasks kernel/hung_task.c:196 [inline]
 watchdog+0x9c4/0xf80 kernel/hung_task.c:252
binder: 31354:31354 transaction failed 29189/-22, size 24-8 line 2852
binder: 31355:31355 transaction failed 29189/-22, size 24-8 line 2852
 kthread+0x345/0x410 kernel/kthread.c:246
binder: 31356:31356 transaction failed 29189/-22, size 24-8 line 2852
 ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:412
Sending NMI from CPU 0 to CPUs 1:
binder: 31358:31358 transaction failed 29189/-22, size 24-8 line 2852
NMI backtrace for cpu 1
CPU: 1 PID: 31358 Comm: syz-executor3 Not tainted 4.18.0-rc5+ #150
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
RIP: 0010:task_tick_fair+0xc6/0x320 kernel/sched/fair.c:9932
Code: 18 00 0f 85 c3 01 00 00 4d 8b bf 50 01 00 00 4d 85 ff 0f 84 4c 01 00 00 49 8d bf 58 01 00 00 48 89 f8 48 c1 e8 03 80 3c 18 00 <0f> 85 91 01 00 00 4d 8b b7 58 01 00 00 4c 89 f7 e8 75 9d ff ff 4c 
RSP: 0018:ffff8801daf079a0 EFLAGS: 00000046
RAX: 1ffff100395534c3 RBX: dffffc0000000000 RCX: 1ffffffff0fd511b
RDX: 0000000000000000 RSI: ffff8801caa9a440 RDI: ffff8801caa9a618
RBP: ffff8801daf079f0 R08: ffff88021fff8058 R09: ffff88021fff805b
R10: ffffed0043fff009 R11: 0000000000000000 R12: 0000000000000001
R13: 0000000000000000 R14: ffff8801daf07ab8 R15: ffff8801caa9a4c0
FS:  00000000025c2940(0000) GS:ffff8801daf00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00000000004cac90 CR3: 00000001be26a000 CR4: 00000000001406e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 <IRQ>
 scheduler_tick+0x18b/0x430 kernel/sched/core.c:3078
 update_process_times+0x51/0x70 kernel/time/timer.c:1641
 tick_sched_handle+0x9f/0x180 kernel/time/tick-sched.c:164
 tick_sched_timer+0x45/0x130 kernel/time/tick-sched.c:1274
 __run_hrtimer kernel/time/hrtimer.c:1398 [inline]
 __hrtimer_run_queues+0x3eb/0x10c0 kernel/time/hrtimer.c:1460
 hrtimer_interrupt+0x2f3/0x750 kernel/time/hrtimer.c:1518
 local_apic_timer_interrupt arch/x86/kernel/apic/apic.c:1025 [inline]
 smp_apic_timer_interrupt+0x165/0x730 arch/x86/kernel/apic/apic.c:1050
 apic_timer_interrupt+0xf/0x20 arch/x86/entry/entry_64.S:863
 </IRQ>
RIP: 0010:arch_local_irq_restore arch/x86/include/asm/paravirt.h:783 [inline]
RIP: 0010:console_trylock_spinning kernel/printk/printk.c:1678 [inline]
RIP: 0010:vprintk_emit+0xbe9/0xdf0 kernel/printk/printk.c:1906
Code: fc ff df 41 80 3c 04 00 0f 85 d4 01 00 00 48 83 3d b3 c1 8e 07 00 0f 84 fe 00 00 00 e8 80 1c 19 00 48 8b bd a8 fe ff ff 57 9d <0f> 1f 44 00 00 e9 18 fe ff ff 41 80 fd 64 0f 84 eb f9 ff ff e9 ef 
RSP: 0018:ffff8801a44ce880 EFLAGS: 00000293 ORIG_RAX: ffffffffffffff13
RAX: ffff8801caa9a440 RBX: 0000000000000200 RCX: 0000000000000000
RDX: 0000000000000000 RSI: ffffffff8162eec0 RDI: 0000000000000293
RBP: ffff8801a44cea10 R08: ffff8801caa9a440 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: 1ffffffff11e360d
R13: 0000000000000045 R14: ffffed0034899d2d R15: ffffffff8aa0c4a0
 vprintk_default+0x28/0x30 kernel/printk/printk.c:1948
 vprintk_func+0x7a/0xe7 kernel/printk/printk_safe.c:382
 printk+0xa7/0xcf kernel/printk/printk.c:1981
 binder_transaction.cold.75+0x1942/0x1afb drivers/android/binder.c:3260
 binder_thread_write+0x858/0x2c30 drivers/android/binder.c:3528
 binder_ioctl_write_read.isra.41+0x2e7/0xb10 drivers/android/binder.c:4456
 binder_ioctl+0xd2f/0x141e drivers/android/binder.c:4596
 vfs_ioctl fs/ioctl.c:46 [inline]
 file_ioctl fs/ioctl.c:500 [inline]
 do_vfs_ioctl+0x1de/0x1720 fs/ioctl.c:684
 ksys_ioctl+0xa9/0xd0 fs/ioctl.c:701
 __do_sys_ioctl fs/ioctl.c:708 [inline]
 __se_sys_ioctl fs/ioctl.c:706 [inline]
 __x64_sys_ioctl+0x73/0xb0 fs/ioctl.c:706
 do_syscall_64+0x1b9/0x820 arch/x86/entry/common.c:290
 entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x455ab9
Code: 1d ba fb ff c3 66 2e 0f 1f 84 00 00 00 00 00 66 90 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 0f 83 eb b9 fb ff c3 66 2e 0f 1f 84 00 00 00 00 
RSP: 002b:00007ffea1e3b5d8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00000000025c2914 RCX: 0000000000455ab9
RDX: 0000000020000440 RSI: 00000000c0306201 RDI: 0000000000000003
RBP: 000000000072bea0 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00000000ffffffff
R13: 00000000004bc64d R14: 00000000004cac90 R15: 0000000000000001

Crashes (7):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2018/07/16 20:53 upstream 706bf68b4339 40cb0c9a .config console log report syz ci-upstream-kasan-gce
2018/06/30 05:48 upstream 1904148a361a dba0b50e .config console log report syz ci-upstream-kasan-gce-root
2018/05/05 08:54 upstream 625e2001e99e 9ce14f4b .config console log report syz ci-upstream-kasan-gce
2018/07/21 05:31 upstream 28c20cc73b9c af255b09 .config console log report syz ci-upstream-kasan-gce-386
2018/07/23 14:57 linux-next 89cf55353308 f69c5fcd .config console log report syz ci-upstream-linux-next-kasan-gce-root
2018/07/22 04:44 linux-next 89cf55353308 8cc079c3 .config console log report syz ci-upstream-linux-next-kasan-gce-root
2018/07/13 08:35 linux-next 3ee15ba60e6b 06c33b3a .config console log report syz ci-upstream-linux-next-kasan-gce-root
* Struck through repros no longer work on HEAD.