bisecting cause commit starting from 36e7985160782bc683001afe09e33a288435def0 building syzkaller on a8529b82fb3bb45832b08a099e7eb51707da9b37 testing commit 36e7985160782bc683001afe09e33a288435def0 with gcc (GCC) 10.2.1 20210217 kernel signature: e40b498cfa37716f873f869838fc78049602d821e260ba37a6c7dee1ec43e34e run #0: crashed: WARNING in bpf_test_run run #1: OK run #2: OK run #3: OK run #4: OK run #5: OK run #6: OK run #7: OK run #8: OK run #9: OK run #10: OK run #11: OK run #12: OK run #13: OK run #14: OK run #15: OK run #16: OK run #17: OK run #18: OK run #19: OK reproducer seems to be flaky testing release v5.11 testing commit f40ddce88593482919761f74910f42f4b84c004b with gcc (GCC) 10.2.1 20210217 kernel signature: e99cd9f143ce9d9fcac692e506c1f42fd7bad007e669bcc2d658384620d3ab58 all runs: OK # git bisect start 36e7985160782bc683001afe09e33a288435def0 f40ddce88593482919761f74910f42f4b84c004b Bisecting: 6667 revisions left to test after this (roughly 13 steps) [d99676af540c2dc829999928fb81c58c80a1dce4] Merge tag 'drm-next-2021-02-19' of git://anongit.freedesktop.org/drm/drm testing commit d99676af540c2dc829999928fb81c58c80a1dce4 with gcc (GCC) 10.2.1 20210217 kernel signature: 5ad479128f117a1d38bc7ee59edcdb592a5fda3fb52cbc77b71fa4437ceb8a6d run #0: crashed: WARNING in kvm_wait run #1: boot failed: WARNING in kvm_wait run #2: boot failed: WARNING in kvm_wait run #3: boot failed: WARNING in kvm_wait run #4: boot failed: WARNING in kvm_wait run #5: crashed: WARNING in kvm_wait run #6: crashed: WARNING in kvm_wait run #7: OK run #8: OK run #9: crashed: WARNING in kvm_wait run #10: OK run #11: OK run #12: OK run #13: OK run #14: OK run #15: OK run #16: OK run #17: OK run #18: OK run #19: OK # git bisect bad d99676af540c2dc829999928fb81c58c80a1dce4 Bisecting: 3717 revisions left to test after this (roughly 12 steps) [f9d58de23152f2c16f326d7e014cfa2933b00304] Merge tag 'affs-for-5.12-tag' of git://git.kernel.org/pub/scm/linux/kernel/git/kdave/linux testing commit f9d58de23152f2c16f326d7e014cfa2933b00304 with gcc (GCC) 10.2.1 20210217 kernel signature: 0e15079a3ab74417003eea81f14abff1aea815e5e366ab0cff272ccab2f025d2 all runs: OK # git bisect good f9d58de23152f2c16f326d7e014cfa2933b00304 Bisecting: 1854 revisions left to test after this (roughly 11 steps) [de1617578849acab8e16c9ffdce39b91fb50639d] Merge tag 'media/v5.12-1' of git://git.kernel.org/pub/scm/linux/kernel/git/mchehab/linux-media testing commit de1617578849acab8e16c9ffdce39b91fb50639d with gcc (GCC) 10.2.1 20210217 kernel signature: 7e28e05eb4da68a9f518c2e311ced71a9dc6276ac4662a3b4b036b603ea6bbcd run #0: basic kernel testing failed: failed to copy test binary to VM: timedout ["scp" "-P" "22" "-F" "/dev/null" "-o" "UserKnownHostsFile=/dev/null" "-o" "BatchMode=yes" "-o" "IdentitiesOnly=yes" "-o" "StrictHostKeyChecking=no" "-o" "ConnectTimeout=10" "/tmp/syz-executor255788897" "root@10.128.1.73:./syz-executor255788897"] Warning: Permanently added '10.128.1.73' (ECDSA) to the list of known hosts. run #1: crashed: WARNING in kvm_wait run #2: boot failed: WARNING in kvm_wait run #3: boot failed: WARNING in kvm_wait run #4: boot failed: WARNING in kvm_wait run #5: boot failed: WARNING in kvm_wait run #6: OK run #7: OK run #8: OK run #9: OK run #10: OK run #11: OK run #12: OK run #13: OK run #14: OK run #15: OK run #16: OK run #17: OK run #18: OK run #19: OK # git bisect bad de1617578849acab8e16c9ffdce39b91fb50639d Bisecting: 929 revisions left to test after this (roughly 10 steps) [4a037ad5d115b2cc79a5071a7854475f365476fa] Merge tag 'for-linus-5.12-rc1-tag' of git://git.kernel.org/pub/scm/linux/kernel/git/xen/tip testing commit 4a037ad5d115b2cc79a5071a7854475f365476fa with gcc (GCC) 10.2.1 20210217 kernel signature: 004ba018d015baabd4e7208e2297f7528a5d4a346a8f96386c9b2e5d310cecf1 run #0: crashed: WARNING in kvm_wait run #1: crashed: WARNING in kvm_wait run #2: crashed: WARNING in kvm_wait run #3: boot failed: WARNING in kvm_wait run #4: boot failed: WARNING in kvm_wait run #5: boot failed: WARNING in kvm_wait run #6: boot failed: WARNING in kvm_wait run #7: crashed: WARNING in kvm_wait run #8: crashed: WARNING in kvm_wait run #9: OK run #10: OK run #11: OK run #12: OK run #13: OK run #14: OK run #15: OK run #16: OK run #17: OK run #18: OK run #19: OK # git bisect bad 4a037ad5d115b2cc79a5071a7854475f365476fa Bisecting: 451 revisions left to test after this (roughly 9 steps) [582cd91f69de8e44857cb610ebca661dac8656b7] Merge tag 'for-5.12/block-2021-02-17' of git://git.kernel.dk/linux-block testing commit 582cd91f69de8e44857cb610ebca661dac8656b7 with gcc (GCC) 10.2.1 20210217 kernel signature: 98a7c4f543254251b4d086d0bfa838a217fd1758106acf0ea8f5cb17b266d9ab all runs: OK # git bisect good 582cd91f69de8e44857cb610ebca661dac8656b7 Bisecting: 247 revisions left to test after this (roughly 8 steps) [3f6ec19f2d05d800bbc42d95dece433da7697864] Merge tag 'timers-core-2021-02-15' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip testing commit 3f6ec19f2d05d800bbc42d95dece433da7697864 with gcc (GCC) 10.2.1 20210217 kernel signature: d9614fad6721e2744d1d2770f3507629fe789ed04a0c63a63802af7053dd7748 all runs: OK # git bisect good 3f6ec19f2d05d800bbc42d95dece433da7697864 Bisecting: 125 revisions left to test after this (roughly 7 steps) [85e853c5ec8486117182baab10c98b321daa6d47] Merge branch 'for-mingo-rcu' of git://git.kernel.org/pub/scm/linux/kernel/git/paulmck/linux-rcu into core/rcu testing commit 85e853c5ec8486117182baab10c98b321daa6d47 with gcc (GCC) 10.2.1 20210217 kernel signature: 7bb2e20bda296641b115400b91f5f7d4a40b610d89203492e82477b640bd46dd all runs: OK # git bisect good 85e853c5ec8486117182baab10c98b321daa6d47 Bisecting: 73 revisions left to test after this (roughly 6 steps) [c5e6fc08feb2b88dc5dac2f3c817e1c2a4cafda4] sched,x86: Allow !PREEMPT_DYNAMIC testing commit c5e6fc08feb2b88dc5dac2f3c817e1c2a4cafda4 with gcc (GCC) 10.2.1 20210217 kernel signature: 1d397b076fdaf75e4844e82e6b33e79d600dbd4869a469d9dca29f8b8229a7f0 all runs: OK # git bisect good c5e6fc08feb2b88dc5dac2f3c817e1c2a4cafda4 Bisecting: 33 revisions left to test after this (roughly 5 steps) [9eef02334505411667a7b51a8f349f8c6c4f3b66] Merge tag 'locking-core-2021-02-17' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip testing commit 9eef02334505411667a7b51a8f349f8c6c4f3b66 with gcc (GCC) 10.2.1 20210217 kernel signature: 946c21ddd5e21761c7bbe8f3f5f788bf15847c180f169c6fed8935dd9f699537 run #0: crashed: WARNING in kvm_wait run #1: crashed: WARNING in kvm_wait run #2: crashed: WARNING in kvm_wait run #3: crashed: WARNING in kvm_wait run #4: crashed: WARNING in kvm_wait run #5: crashed: WARNING in kvm_wait run #6: crashed: WARNING in kvm_wait run #7: boot failed: WARNING in kvm_wait run #8: boot failed: WARNING in kvm_wait run #9: boot failed: WARNING in kvm_wait run #10: boot failed: WARNING in kvm_wait run #11: boot failed: WARNING in kvm_wait run #12: crashed: WARNING in kvm_wait run #13: OK run #14: OK run #15: OK run #16: OK run #17: OK run #18: crashed: WARNING in kvm_wait run #19: OK # git bisect bad 9eef02334505411667a7b51a8f349f8c6c4f3b66 Bisecting: 19 revisions left to test after this (roughly 4 steps) [62137364e3e8afcc745846c5c67cacf943149073] Merge branch 'linus' into locking/core, to pick up upstream fixes testing commit 62137364e3e8afcc745846c5c67cacf943149073 with gcc (GCC) 10.2.1 20210217 kernel signature: dd66e5e6f419a6c0e47632da6e52772605bf95682fd106eabfa38602abf67e5a run #0: crashed: WARNING in kvm_wait run #1: crashed: WARNING in kvm_wait run #2: crashed: WARNING in kvm_wait run #3: crashed: WARNING in kvm_wait run #4: boot failed: WARNING in kvm_wait run #5: OK run #6: OK run #7: OK run #8: OK run #9: crashed: WARNING in kvm_wait run #10: OK run #11: OK run #12: OK run #13: OK run #14: OK run #15: crashed: WARNING in kvm_wait run #16: OK run #17: OK run #18: OK run #19: OK # git bisect bad 62137364e3e8afcc745846c5c67cacf943149073 Bisecting: 9 revisions left to test after this (roughly 3 steps) [997acaf6b4b59c6a9c259740312a69ea549cc684] lockdep: report broken irq restoration testing commit 997acaf6b4b59c6a9c259740312a69ea549cc684 with gcc (GCC) 10.2.1 20210217 kernel signature: 8ef728c50e58e18ab476595de69411c38a65aeb9076e859a67a7be5e88f6cf4f run #0: crashed: WARNING in kvm_wait run #1: crashed: WARNING in kvm_wait run #2: crashed: WARNING in kvm_wait run #3: basic kernel testing failed: failed to copy test binary to VM: timedout ["scp" "-P" "22" "-F" "/dev/null" "-o" "UserKnownHostsFile=/dev/null" "-o" "BatchMode=yes" "-o" "IdentitiesOnly=yes" "-o" "StrictHostKeyChecking=no" "-o" "ConnectTimeout=10" "/tmp/syz-executor253060380" "root@10.128.10.8:./syz-executor253060380"] Warning: Permanently added '10.128.10.8' (ECDSA) to the list of known hosts. run #4: basic kernel testing failed: failed to copy test binary to VM: timedout ["scp" "-P" "22" "-F" "/dev/null" "-o" "UserKnownHostsFile=/dev/null" "-o" "BatchMode=yes" "-o" "IdentitiesOnly=yes" "-o" "StrictHostKeyChecking=no" "-o" "ConnectTimeout=10" "/tmp/syz-executor205260462" "root@10.128.1.52:./syz-executor205260462"] Warning: Permanently added '10.128.1.52' (ECDSA) to the list of known hosts. run #5: basic kernel testing failed: failed to copy test binary to VM: timedout ["scp" "-P" "22" "-F" "/dev/null" "-o" "UserKnownHostsFile=/dev/null" "-o" "BatchMode=yes" "-o" "IdentitiesOnly=yes" "-o" "StrictHostKeyChecking=no" "-o" "ConnectTimeout=10" "/tmp/syz-executor127893203" "root@10.128.10.18:./syz-executor127893203"] Warning: Permanently added '10.128.10.18' (ECDSA) to the list of known hosts. run #6: basic kernel testing failed: failed to copy test binary to VM: timedout ["scp" "-P" "22" "-F" "/dev/null" "-o" "UserKnownHostsFile=/dev/null" "-o" "BatchMode=yes" "-o" "IdentitiesOnly=yes" "-o" "StrictHostKeyChecking=no" "-o" "ConnectTimeout=10" "/tmp/syz-executor602136086" "root@10.128.0.94:./syz-executor602136086"] Warning: Permanently added '10.128.0.94' (ECDSA) to the list of known hosts. run #7: crashed: WARNING in kvm_wait run #8: boot failed: WARNING in kvm_wait run #9: boot failed: WARNING in kvm_wait run #10: boot failed: WARNING in kvm_wait run #11: crashed: WARNING in kvm_wait run #12: crashed: WARNING in kvm_wait run #13: OK run #14: crashed: WARNING in kvm_wait run #15: OK run #16: OK run #17: OK run #18: OK run #19: OK # git bisect bad 997acaf6b4b59c6a9c259740312a69ea549cc684 Bisecting: 4 revisions left to test after this (roughly 2 steps) [175b1a60e8805617d74aefe17ce0d3a32eceb55c] locking/lockdep: Clean up check_redundant() a bit testing commit 175b1a60e8805617d74aefe17ce0d3a32eceb55c with gcc (GCC) 10.2.1 20210217 kernel signature: 5bc32e5270ebcfa2da76f60758a0f1155c8c51bde2b7d64935ef0765cdbcf66a all runs: OK # git bisect good 175b1a60e8805617d74aefe17ce0d3a32eceb55c Bisecting: 2 revisions left to test after this (roughly 1 step) [7e923e6a3ceb877497dd9ee70d71fa33b94f332b] locking/selftests: Add local_lock inversion tests testing commit 7e923e6a3ceb877497dd9ee70d71fa33b94f332b with gcc (GCC) 10.2.1 20210217 kernel signature: 79e68a82e05d1c272b4ead924b35db0ce607c910a4d972eed30e02224f73c93a all runs: OK # git bisect good 7e923e6a3ceb877497dd9ee70d71fa33b94f332b Bisecting: 0 revisions left to test after this (roughly 1 step) [2f0df49c89acaa58571d509830bc481250699885] jump_label: Do not profile branch annotations testing commit 2f0df49c89acaa58571d509830bc481250699885 with gcc (GCC) 10.2.1 20210217 kernel signature: 79e68a82e05d1c272b4ead924b35db0ce607c910a4d972eed30e02224f73c93a all runs: OK # git bisect good 2f0df49c89acaa58571d509830bc481250699885 997acaf6b4b59c6a9c259740312a69ea549cc684 is the first bad commit commit 997acaf6b4b59c6a9c259740312a69ea549cc684 Author: Mark Rutland Date: Mon Jan 11 15:37:07 2021 +0000 lockdep: report broken irq restoration We generally expect local_irq_save() and local_irq_restore() to be paired and sanely nested, and so local_irq_restore() expects to be called with irqs disabled. Thus, within local_irq_restore() we only trace irq flag changes when unmasking irqs. This means that a sequence such as: | local_irq_disable(); | local_irq_save(flags); | local_irq_enable(); | local_irq_restore(flags); ... is liable to break things, as the local_irq_restore() would mask irqs without tracing this change. Similar problems may exist for architectures whose arch_irq_restore() function depends on being called with irqs disabled. We don't consider such sequences to be a good idea, so let's define those as forbidden, and add tooling to detect such broken cases. This patch adds debug code to WARN() when raw_local_irq_restore() is called with irqs enabled. As raw_local_irq_restore() is expected to pair with raw_local_irq_save(), it should never be called with irqs enabled. To avoid the possibility of circular header dependencies between irqflags.h and bug.h, the warning is handled in a separate C file. The new code is all conditional on a new CONFIG_DEBUG_IRQFLAGS symbol which is independent of CONFIG_TRACE_IRQFLAGS. As noted above such cases will confuse lockdep, so CONFIG_DEBUG_LOCKDEP now selects CONFIG_DEBUG_IRQFLAGS. Signed-off-by: Mark Rutland Signed-off-by: Peter Zijlstra (Intel) Link: https://lkml.kernel.org/r/20210111153707.10071-1-mark.rutland@arm.com include/linux/irqflags.h | 12 ++++++++++++ kernel/locking/Makefile | 1 + kernel/locking/irqflag-debug.c | 11 +++++++++++ lib/Kconfig.debug | 8 ++++++++ 4 files changed, 32 insertions(+) create mode 100644 kernel/locking/irqflag-debug.c culprit signature: 8ef728c50e58e18ab476595de69411c38a65aeb9076e859a67a7be5e88f6cf4f parent signature: 79e68a82e05d1c272b4ead924b35db0ce607c910a4d972eed30e02224f73c93a Reproducer flagged being flaky revisions tested: 16, total time: 4h56m34.969090119s (build: 1h44m57.841448191s, test: 3h9m12.664151164s) first bad commit: 997acaf6b4b59c6a9c259740312a69ea549cc684 lockdep: report broken irq restoration recipients (to): ["linux-kernel@vger.kernel.org" "mark.rutland@arm.com" "mingo@redhat.com" "peterz@infradead.org" "peterz@infradead.org" "will@kernel.org"] recipients (cc): ["akpm@linux-foundation.org" "masahiroy@kernel.org" "rafael.j.wysocki@intel.com" "rostedt@goodmis.org" "tglx@linutronix.de"] crash: WARNING in kvm_wait ------------[ cut here ]------------ raw_local_irq_restore() called with IRQs enabled WARNING: CPU: 0 PID: 22414 at kernel/locking/irqflag-debug.c:9 warn_bogus_irq_restore kernel/locking/irqflag-debug.c:9 [inline] WARNING: CPU: 0 PID: 22414 at kernel/locking/irqflag-debug.c:9 warn_bogus_irq_restore+0x1d/0x20 kernel/locking/irqflag-debug.c:7 Modules linked in: CPU: 0 PID: 22414 Comm: kworker/0:11 Not tainted 5.11.0-rc2-syzkaller #0 Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011 Workqueue: events bpf_prog_free_deferred RIP: 0010:warn_bogus_irq_restore kernel/locking/irqflag-debug.c:9 [inline] RIP: 0010:warn_bogus_irq_restore+0x1d/0x20 kernel/locking/irqflag-debug.c:7 Code: 51 00 e9 3f fe ff ff cc cc cc cc cc cc 80 3d e0 b6 ce 0a 00 74 01 c3 48 c7 c7 60 f5 8a 88 c6 05 cf b6 ce 0a 01 e8 17 01 a4 06 <0f> 0b c3 48 c7 c0 a0 46 4d 8e 53 48 89 fb 48 ba 00 00 00 00 00 fc RSP: 0018:ffffc90001807990 EFLAGS: 00010282 RAX: 0000000000000000 RBX: ffffffff8a875aa0 RCX: 0000000000000000 RDX: 0000000000000002 RSI: 0000000000000004 RDI: fffff52000300f24 RBP: 0000000000000246 R08: 0000000000000001 R09: ffff8880b9e2015b R10: ffffed10173c402b R11: 0000000000000001 R12: 0000000000000003 R13: fffffbfff150eb54 R14: 0000000000000001 R15: ffff8880b9e359c0 FS: 0000000000000000(0000) GS:ffff8880b9e00000(0000) knlGS:0000000000000000 CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 CR2: 00000000200004e0 CR3: 0000000011491000 CR4: 00000000001506f0 DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 Call Trace: kvm_wait arch/x86/kernel/kvm.c:860 [inline] kvm_wait+0xc3/0xe0 arch/x86/kernel/kvm.c:837 pv_wait arch/x86/include/asm/paravirt.h:564 [inline] pv_wait_head_or_lock kernel/locking/qspinlock_paravirt.h:470 [inline] __pv_queued_spin_lock_slowpath+0x8b8/0xb40 kernel/locking/qspinlock.c:508 pv_queued_spin_lock_slowpath arch/x86/include/asm/paravirt.h:554 [inline] queued_spin_lock_slowpath arch/x86/include/asm/qspinlock.h:51 [inline] queued_spin_lock include/asm-generic/qspinlock.h:85 [inline] do_raw_spin_lock+0x200/0x2b0 kernel/locking/spinlock_debug.c:113 spin_lock include/linux/spinlock.h:354 [inline] __purge_vmap_area_lazy+0x23b/0x2320 mm/vmalloc.c:1363 _vm_unmap_aliases.part.0+0x300/0x3d0 mm/vmalloc.c:1784 _vm_unmap_aliases mm/vmalloc.c:1758 [inline] vm_remove_mappings mm/vmalloc.c:2250 [inline] __vunmap+0x4a4/0x940 mm/vmalloc.c:2277 bpf_jit_free+0x9e/0x190 process_one_work+0x84c/0x13b0 kernel/workqueue.c:2275 worker_thread+0x598/0xf80 kernel/workqueue.c:2421 kthread+0x36f/0x450 kernel/kthread.c:292 ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:296