bisecting fixing commit since bfb9e5c03076a446b1f4f6a523ddc8d723c907a6 building syzkaller on 79b211f74b08737aeb4934c6ff69a263b3c38013 testing commit bfb9e5c03076a446b1f4f6a523ddc8d723c907a6 with gcc (GCC) 8.1.0 kernel signature: a5c43fb7df6f9e3378723c1477de04a1b2e779fc run #0: crashed: INFO: task hung in pipe_write run #1: crashed: INFO: task hung in pipe_write run #2: crashed: INFO: task hung in pipe_write run #3: crashed: INFO: task hung in pipe_write run #4: crashed: INFO: task hung in pipe_read run #5: crashed: INFO: task hung in pipe_write run #6: crashed: INFO: task hung in pipe_write run #7: crashed: INFO: task hung in pipe_write run #8: crashed: INFO: task hung in pipe_read run #9: OK testing current HEAD c1141b3aab36eb0d9b2bcae4aff69e77d0554386 testing commit c1141b3aab36eb0d9b2bcae4aff69e77d0554386 with gcc (GCC) 8.1.0 kernel signature: 82ca91a183be89ce3e8855122bc190dd79676887 run #0: crashed: INFO: task hung in pipe_write run #1: crashed: INFO: task hung in pipe_write run #2: crashed: INFO: task hung in pipe_write run #3: crashed: INFO: task hung in pipe_write run #4: crashed: INFO: task hung in pipe_write run #5: crashed: INFO: task hung in pipe_write run #6: crashed: INFO: task hung in pipe_write run #7: crashed: INFO: task hung in pipe_write run #8: crashed: INFO: task hung in pipe_write run #9: crashed: INFO: task hung in pipe_read revisions tested: 2, total time: 37m6.562767704s (build: 17m19.543416562s, test: 19m24.478997433s) the crash still happens on HEAD commit msg: Linux 4.14.166 crash: INFO: task hung in pipe_read INFO: task syz-execprog:7103 blocked for more than 140 seconds. Not tainted 4.14.166-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-execprog D27544 7103 7088 0x00000004 Call Trace: context_switch kernel/sched/core.c:2808 [inline] __schedule+0x780/0x1d20 kernel/sched/core.c:3384 schedule+0x7f/0x1b0 kernel/sched/core.c:3428 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3486 __mutex_lock_common kernel/locking/mutex.c:833 [inline] __mutex_lock+0xabc/0x14c0 kernel/locking/mutex.c:893 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908 pipe_lock_nested fs/pipe.c:67 [inline] pipe_lock fs/pipe.c:75 [inline] pipe_wait+0x16c/0x190 fs/pipe.c:123 pipe_read+0x2c0/0x7b0 fs/pipe.c:352 call_read_iter include/linux/fs.h:1771 [inline] new_sync_read fs/read_write.c:401 [inline] __vfs_read+0x410/0x840 fs/read_write.c:413 vfs_read+0xf5/0x300 fs/read_write.c:447 SYSC_read fs/read_write.c:574 [inline] SyS_read+0x100/0x250 fs/read_write.c:567 do_syscall_64+0x1c7/0x5b0 arch/x86/entry/common.c:292 entry_SYSCALL_64_after_hwframe+0x42/0xb7 RIP: 0033:0x47ea10 RSP: 002b:000000c42002cd88 EFLAGS: 00000212 ORIG_RAX: 0000000000000000 RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 000000000047ea10 RDX: 0000000000010000 RSI: 000000c420246000 RDI: 0000000000000028 RBP: 000000c42002cde0 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000212 R12: 000000c42019ef50 R13: 0000000000000001 R14: 000000c42030a7e0 R15: 0000000000000001 INFO: task syz-execprog:7724 blocked for more than 140 seconds. Not tainted 4.14.166-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-execprog D28136 7724 7088 0x00000004 Call Trace: context_switch kernel/sched/core.c:2808 [inline] __schedule+0x780/0x1d20 kernel/sched/core.c:3384 schedule+0x7f/0x1b0 kernel/sched/core.c:3428 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3486 __mutex_lock_common kernel/locking/mutex.c:833 [inline] __mutex_lock+0xabc/0x14c0 kernel/locking/mutex.c:893 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908 pipe_lock_nested fs/pipe.c:67 [inline] pipe_lock fs/pipe.c:75 [inline] pipe_wait+0x16c/0x190 fs/pipe.c:123 pipe_read+0x2c0/0x7b0 fs/pipe.c:352 call_read_iter include/linux/fs.h:1771 [inline] new_sync_read fs/read_write.c:401 [inline] __vfs_read+0x410/0x840 fs/read_write.c:413 vfs_read+0xf5/0x300 fs/read_write.c:447 SYSC_read fs/read_write.c:574 [inline] SyS_read+0x100/0x250 fs/read_write.c:567 do_syscall_64+0x1c7/0x5b0 arch/x86/entry/common.c:292 entry_SYSCALL_64_after_hwframe+0x42/0xb7 RIP: 0033:0x47ea10 RSP: 002b:000000c4201a3588 EFLAGS: 00000212 ORIG_RAX: 0000000000000000 RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 000000000047ea10 RDX: 0000000000010000 RSI: 000000c4204ae000 RDI: 0000000000000018 RBP: 000000c4201a35e0 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000212 R12: 000000c42019ff50 R13: 0000000000000001 R14: 000000c4201e8540 R15: 0000000000000001 INFO: task syz-executor.1:26320 blocked for more than 140 seconds. Not tainted 4.14.166-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.1 D29464 26320 11523 0x00000000 Call Trace: context_switch kernel/sched/core.c:2808 [inline] __schedule+0x780/0x1d20 kernel/sched/core.c:3384 schedule+0x7f/0x1b0 kernel/sched/core.c:3428 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3486 __mutex_lock_common kernel/locking/mutex.c:833 [inline] __mutex_lock+0xabc/0x14c0 kernel/locking/mutex.c:893 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908 __pipe_lock fs/pipe.c:88 [inline] pipe_write+0xa6/0xd10 fs/pipe.c:385 call_write_iter include/linux/fs.h:1777 [inline] new_sync_write fs/read_write.c:469 [inline] __vfs_write+0x413/0x840 fs/read_write.c:482 vfs_write+0x150/0x4f0 fs/read_write.c:544 SYSC_write fs/read_write.c:590 [inline] SyS_write+0x100/0x250 fs/read_write.c:582 do_syscall_64+0x1c7/0x5b0 arch/x86/entry/common.c:292 entry_SYSCALL_64_after_hwframe+0x42/0xb7 RIP: 0033:0x45a919 RSP: 002b:00007f4e028adc78 EFLAGS: 00000246 ORIG_RAX: 0000000000000001 RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 000000000045a919 RDX: 000000010000000d RSI: 0000000020000000 RDI: 0000000000000000 RBP: 000000000075bf20 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000246 R12: 00007f4e028ae6d4 R13: 00000000004cbe11 R14: 00000000004e5be8 R15: 00000000ffffffff INFO: task syz-executor.1:30216 blocked for more than 140 seconds. Not tainted 4.14.166-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.1 D29256 30216 11523 0x00000000 Call Trace: context_switch kernel/sched/core.c:2808 [inline] __schedule+0x780/0x1d20 kernel/sched/core.c:3384 schedule+0x7f/0x1b0 kernel/sched/core.c:3428 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3486 __mutex_lock_common kernel/locking/mutex.c:833 [inline] __mutex_lock+0xabc/0x14c0 kernel/locking/mutex.c:893 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908 __pipe_lock fs/pipe.c:88 [inline] pipe_write+0xa6/0xd10 fs/pipe.c:385 call_write_iter include/linux/fs.h:1777 [inline] new_sync_write fs/read_write.c:469 [inline] __vfs_write+0x413/0x840 fs/read_write.c:482 vfs_write+0x150/0x4f0 fs/read_write.c:544 SYSC_write fs/read_write.c:590 [inline] SyS_write+0x100/0x250 fs/read_write.c:582 do_syscall_64+0x1c7/0x5b0 arch/x86/entry/common.c:292 entry_SYSCALL_64_after_hwframe+0x42/0xb7 RIP: 0033:0x45a919 RSP: 002b:00007f4e028adc78 EFLAGS: 00000246 ORIG_RAX: 0000000000000001 RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 000000000045a919 RDX: 000000010000000d RSI: 0000000020000000 RDI: 0000000000000000 RBP: 000000000075bf20 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000246 R12: 00007f4e028ae6d4 R13: 00000000004cbe11 R14: 00000000004e5be8 R15: 00000000ffffffff INFO: task syz-executor.0:30217 blocked for more than 140 seconds. Not tainted 4.14.166-syzkaller #0 "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. syz-executor.0 D29608 30217 7117 0x00000000 Call Trace: context_switch kernel/sched/core.c:2808 [inline] __schedule+0x780/0x1d20 kernel/sched/core.c:3384 schedule+0x7f/0x1b0 kernel/sched/core.c:3428 schedule_preempt_disabled+0x13/0x20 kernel/sched/core.c:3486 __mutex_lock_common kernel/locking/mutex.c:833 [inline] __mutex_lock+0xabc/0x14c0 kernel/locking/mutex.c:893 mutex_lock_nested+0x16/0x20 kernel/locking/mutex.c:908 __pipe_lock fs/pipe.c:88 [inline] pipe_write+0xa6/0xd10 fs/pipe.c:385 call_write_iter include/linux/fs.h:1777 [inline] new_sync_write fs/read_write.c:469 [inline] __vfs_write+0x413/0x840 fs/read_write.c:482 vfs_write+0x150/0x4f0 fs/read_write.c:544 SYSC_write fs/read_write.c:590 [inline] SyS_write+0x100/0x250 fs/read_write.c:582 do_syscall_64+0x1c7/0x5b0 arch/x86/entry/common.c:292 entry_SYSCALL_64_after_hwframe+0x42/0xb7 RIP: 0033:0x45a919 RSP: 002b:00007f3068aebc78 EFLAGS: 00000246 ORIG_RAX: 0000000000000001 RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 000000000045a919 RDX: 000000010000000d RSI: 0000000020000000 RDI: 0000000000000000 RBP: 000000000075bf20 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000000 R11: 0000000000000246 R12: 00007f3068aec6d4 R13: 00000000004cbe11 R14: 00000000004e5be8 R15: 00000000ffffffff Showing all locks held in the system: 1 lock held by khungtaskd/1044: #0: (tasklist_lock){.+.+}, at: [] debug_show_all_locks+0x79/0x218 kernel/locking/lockdep.c:4544 1 lock held by rsyslogd/6872: #0: (&f->f_pos_lock){+.+.}, at: [] __fdget_pos+0x8e/0xc0 fs/file.c:769 2 locks held by getty/6993: #0: (&tty->ldisc_sem){++++}, at: [] ldsem_down_read+0x2d/0x40 drivers/tty/tty_ldsem.c:376 #1: (&ldata->atomic_read_lock){+.+.}, at: [] n_tty_read+0x1e6/0x18f0 drivers/tty/n_tty.c:2156 2 locks held by getty/6994: #0: (&tty->ldisc_sem){++++}, at: [] ldsem_down_read+0x2d/0x40 drivers/tty/tty_ldsem.c:376 #1: (&ldata->atomic_read_lock){+.+.}, at: [] n_tty_read+0x1e6/0x18f0 drivers/tty/n_tty.c:2156 2 locks held by getty/6995: #0: (&tty->ldisc_sem){++++}, at: [] ldsem_down_read+0x2d/0x40 drivers/tty/tty_ldsem.c:376 #1: (&ldata->atomic_read_lock){+.+.}, at: [] n_tty_read+0x1e6/0x18f0 drivers/tty/n_tty.c:2156 2 locks held by getty/6996: #0: (&tty->ldisc_sem){++++}, at: [] ldsem_down_read+0x2d/0x40 drivers/tty/tty_ldsem.c:376 #1: (&ldata->atomic_read_lock){+.+.}, at: [] n_tty_read+0x1e6/0x18f0 drivers/tty/n_tty.c:2156 2 locks held by getty/6997: #0: (&tty->ldisc_sem){++++}, at: [] ldsem_down_read+0x2d/0x40 drivers/tty/tty_ldsem.c:376 #1: (&ldata->atomic_read_lock){+.+.}, at: [] n_tty_read+0x1e6/0x18f0 drivers/tty/n_tty.c:2156 2 locks held by getty/6998: #0: (&tty->ldisc_sem){++++}, at: [] ldsem_down_read+0x2d/0x40 drivers/tty/tty_ldsem.c:376 #1: (&ldata->atomic_read_lock){+.+.}, at: [] n_tty_read+0x1e6/0x18f0 drivers/tty/n_tty.c:2156 2 locks held by getty/6999: #0: (&tty->ldisc_sem){++++}, at: [] ldsem_down_read+0x2d/0x40 drivers/tty/tty_ldsem.c:376 #1: (&ldata->atomic_read_lock){+.+.}, at: [] n_tty_read+0x1e6/0x18f0 drivers/tty/n_tty.c:2156 1 lock held by syz-execprog/7103: #0: (&pipe->mutex/1){+.+.}, at: [] pipe_lock_nested fs/pipe.c:67 [inline] #0: (&pipe->mutex/1){+.+.}, at: [] pipe_lock fs/pipe.c:75 [inline] #0: (&pipe->mutex/1){+.+.}, at: [] pipe_wait+0x16c/0x190 fs/pipe.c:123 1 lock held by syz-execprog/7724: #0: (&pipe->mutex/1){+.+.}, at: [] pipe_lock_nested fs/pipe.c:67 [inline] #0: (&pipe->mutex/1){+.+.}, at: [] pipe_lock fs/pipe.c:75 [inline] #0: (&pipe->mutex/1){+.+.}, at: [] pipe_wait+0x16c/0x190 fs/pipe.c:123 1 lock held by syz-executor.0/7695: #0: (&pipe->mutex/1){+.+.}, at: [] pipe_lock_nested fs/pipe.c:67 [inline] #0: (&pipe->mutex/1){+.+.}, at: [] pipe_lock fs/pipe.c:75 [inline] #0: (&pipe->mutex/1){+.+.}, at: [] pipe_wait+0x16c/0x190 fs/pipe.c:123 1 lock held by syz-executor.4/20830: #0: (&pipe->mutex/1){+.+.}, at: [] pipe_lock_nested fs/pipe.c:67 [inline] #0: (&pipe->mutex/1){+.+.}, at: [] pipe_lock fs/pipe.c:75 [inline] #0: (&pipe->mutex/1){+.+.}, at: [] pipe_wait+0x16c/0x190 fs/pipe.c:123 1 lock held by syz-executor.3/11443: #0: (&pipe->mutex/1){+.+.}, at: [] pipe_lock_nested fs/pipe.c:67 [inline] #0: (&pipe->mutex/1){+.+.}, at: [] pipe_lock fs/pipe.c:75 [inline] #0: (&pipe->mutex/1){+.+.}, at: [] pipe_wait+0x16c/0x190 fs/pipe.c:123 1 lock held by syz-executor.1/23511: #0: (&pipe->mutex/1){+.+.}, at: [] pipe_lock_nested fs/pipe.c:67 [inline] #0: (&pipe->mutex/1){+.+.}, at: [] pipe_lock fs/pipe.c:75 [inline] #0: (&pipe->mutex/1){+.+.}, at: [] pipe_wait+0x16c/0x190 fs/pipe.c:123 1 lock held by syz-executor.1/26320: #0: (&pipe->mutex/1){+.+.}, at: [] __pipe_lock fs/pipe.c:88 [inline] #0: (&pipe->mutex/1){+.+.}, at: [] pipe_write+0xa6/0xd10 fs/pipe.c:385 1 lock held by syz-executor.1/30216: #0: (&pipe->mutex/1){+.+.}, at: [] __pipe_lock fs/pipe.c:88 [inline] #0: (&pipe->mutex/1){+.+.}, at: [] pipe_write+0xa6/0xd10 fs/pipe.c:385 1 lock held by syz-executor.0/30217: #0: (&pipe->mutex/1){+.+.}, at: [] __pipe_lock fs/pipe.c:88 [inline] #0: (&pipe->mutex/1){+.+.}, at: [] pipe_write+0xa6/0xd10 fs/pipe.c:385 1 lock held by syz-executor.4/5041: #0: (&pipe->mutex/1){+.+.}, at: [] __pipe_lock fs/pipe.c:88 [inline] #0: (&pipe->mutex/1){+.+.}, at: [] pipe_write+0xa6/0xd10 fs/pipe.c:385 1 lock held by syz-executor.0/15538: #0: (&pipe->mutex/1){+.+.}, at: [] __pipe_lock fs/pipe.c:88 [inline] #0: (&pipe->mutex/1){+.+.}, at: [] pipe_write+0xa6/0xd10 fs/pipe.c:385 1 lock held by syz-executor.5/21528: #0: (&pipe->mutex/1){+.+.}, at: [] pipe_lock_nested fs/pipe.c:67 [inline] #0: (&pipe->mutex/1){+.+.}, at: [] pipe_lock fs/pipe.c:75 [inline] #0: (&pipe->mutex/1){+.+.}, at: [] pipe_wait+0x16c/0x190 fs/pipe.c:123 1 lock held by syz-executor.0/27074: #0: (&pipe->mutex/1){+.+.}, at: [] __pipe_lock fs/pipe.c:88 [inline] #0: (&pipe->mutex/1){+.+.}, at: [] pipe_write+0xa6/0xd10 fs/pipe.c:385 1 lock held by syz-executor.0/27086: #0: (&pipe->mutex/1){+.+.}, at: [] __pipe_lock fs/pipe.c:88 [inline] #0: (&pipe->mutex/1){+.+.}, at: [] pipe_write+0xa6/0xd10 fs/pipe.c:385 ============================================= NMI backtrace for cpu 0 CPU: 0 PID: 1044 Comm: khungtaskd Not tainted 4.14.166-syzkaller #0 Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 Call Trace: __dump_stack lib/dump_stack.c:17 [inline] dump_stack+0xf7/0x13b lib/dump_stack.c:58 nmi_cpu_backtrace.cold.4+0x3e/0x76 lib/nmi_backtrace.c:101 nmi_trigger_cpumask_backtrace+0xe5/0x119 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:140 [inline] check_hung_uninterruptible_tasks kernel/hung_task.c:195 [inline] watchdog+0x522/0xb40 kernel/hung_task.c:274 kthread+0x338/0x400 kernel/kthread.c:232 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404 Sending NMI from CPU 0 to CPUs 1: NMI backtrace for cpu 1 CPU: 1 PID: 94 Comm: kworker/u4:3 Not tainted 4.14.166-syzkaller #0 Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 Workqueue: bat_events batadv_nc_worker task: ffff8880a9a36300 task.stack: ffff8880a9a40000 RIP: 0010:__lock_acquire+0x338/0x4500 kernel/locking/lockdep.c:3428 RSP: 0018:ffff8880a9a47ac0 EFLAGS: 00000006 RAX: ffff8880a9a36b80 RBX: 0000000000000012 RCX: 0000000000000002 RDX: 000000000000066b RSI: 0000000000000012 RDI: ffff8880a9a36bc8 RBP: ffff8880a9a47c88 R08: 0000000000000000 R09: 0000000000000000 R10: 0000000000000050 R11: ffff8880a9a36300 R12: ffffffff87f889e0 R13: 0000000000000000 R14: 0000000000000002 R15: ffff8880a9a36bd0 FS: 0000000000000000(0000) GS:ffff8880aed00000(0000) knlGS:0000000000000000 CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 CR2: 00007f25849eb140 CR3: 000000009ee3e000 CR4: 00000000001406e0 DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 Call Trace: lock_acquire+0x173/0x400 kernel/locking/lockdep.c:3994 rcu_lock_acquire include/linux/rcupdate.h:242 [inline] rcu_read_lock include/linux/rcupdate.h:629 [inline] batadv_nc_purge_orig_hash net/batman-adv/network-coding.c:416 [inline] batadv_nc_worker+0xef/0x630 net/batman-adv/network-coding.c:726 process_one_work+0x79e/0x16c0 kernel/workqueue.c:2114 worker_thread+0xcc/0xee0 kernel/workqueue.c:2248 kthread+0x338/0x400 kernel/kthread.c:232 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404 Code: b7 50 20 81 e2 ff 1f 00 00 39 da 75 0b 48 83 7d 10 00 0f 85 ba 07 00 00 48 8b 84 24 88 00 00 00 89 de 66 81 e6 ff 1f 4e 8d 3c 10 <49> 8d 47 20 48 89 c2 48 89 44 24 78 48 b8 00 00 00 00 00 fc ff