On Fri, Sep 25, 2020 at 09:14:16AM +0800, Ming Lei wrote: > On Thu, Sep 24, 2020 at 10:33:45AM -0400, Theodore Y. Ts'o wrote: > > On Thu, Sep 24, 2020 at 08:59:01AM +0800, Ming Lei wrote: > > > > > > The list corruption issue can be reproduced on kvm/qumu guest too when > > > running xfstests(ext4) generic/038. > > > > > > However, the issue may become not reproduced when adding or removing memory > > > debug options, such as adding KASAN. > > > > Can you reliably reprodue this crash? And if so, with what config and > > what kernel version. > > Yeah, it can be reproduced reliably by running xfstests(ext4) > generic/038 over virtio-scsi(test device)/virtio-blk(scratch device). > > The kernel is -rc4, and not test -rc5 yet. > > It is exactly the config you provided, and I just enabled CDROM & ISOFS > against your config for passing cloud-init data via cdrom to VM. > > > One of the reasons why I had gone silent on this bug is that I've been > > trying many, many configurations and configurations which reliably > > reproduced on say, -rc4 would not reproduce on -rc5, and then I would > > get a completely different set of results on -rc6. So I've been > > trying to run a lot of different experiments to try to understand what > > might be going on, since it seems pretty clear this must be a very > > timing-sensitive failure. > > > > I also found that the re-occrance went down significantly if I enabled > > KASAN, and while it didn't go away, I wasn't able to get a KASAN > > failure to trigger, either. Turning off CONFIG_PROVE_LOCKING and a > > *lot* of other debugging configs made the problem vanish in -rc4, but > > that trick didn't work with -rc5 or -rc6. > > The issue can be reproduced reliably in my environment after > disabling LOCKDEP only for disabling KMEMLEAK only. > > But after disabling DEBUG_OBJECTS, it becomes hard to trigger. > > > > > Each time I discovered one of these things, I was about to post to the > > e-mail thread, only to have a confirmation test run on a different > > kernel version make the problem go away. In particular, your revert > > helped with -rc4 and -rc6 IIRC, but it didn't help in -rc5..... > > > > HOWEVER, thanks to a hint from a colleague at $WORK, and realizing > > that one of the stack traces had virtio balloon in the trace, I > > realized that when I switched the GCE VM type from e1-standard-2 to > > n1-standard-2 (where e1 VM's are cheaper because they use > > virtio-balloon to better manage host OS memory utilization), problem > > has become, much, *much* rarer (and possibly has gone away, although > > I'm going to want to run a lot more tests before I say that > > conclusively) on my test setup. At the very least, using an n1 VM > > (which doesn't have virtio-balloon enabled in the hypervisor) is > > enough to unblock ext4 development. > > > > Any chance your kvm/qemu configuration might have been using > > virtio-ballon? Because other ext4 developers who have been using > > kvm-xftests have not had any problems.... > > I don't setup virtio-ballon, see the attached script for setting the VM. > > > > > > When I enable PAGE_POISONING, double free on kmalloc(192) is captured: > > > > > > [ 1198.317139] slab: double free detected in cache 'kmalloc-192', objp ffff89ada7584300^M > > > [ 1198.326651] ------------[ cut here ]------------^M > > > [ 1198.327969] kernel BUG at mm/slab.c:2535!^M > > > [ 1198.329129] invalid opcode: 0000 [#1] SMP PTI^M > > > [ 1198.333776] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 5.9.0-rc4_quiesce_srcu-xfstests #102^M > > > [ 1198.336085] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.13.0-48-gd9c812dda519-prebuilt.qemu.org 04/01/2014^M > > > [ 1198.339826] RIP: 0010:free_block.cold.92+0x13/0x15^M > > > [ 1198.341472] Code: 8d 44 05 f0 eb d0 48 63 83 e0 00 00 00 48 8d 54 05 f8 e9 4b 81 ff ff 48 8b 73 58 48 89 ea 48 c7 c7 98 e7 4a 9c e8 20 c3 eb ff <0f> 0b 48 8b 73 58 48 c7 c2 20 e8 4a 9c 48 c7 c7 70 32 22 9c e8 19^M > > > [ 1198.347331] RSP: 0018:ffff982e40710be8 EFLAGS: 00010046^M > > > [ 1198.349091] RAX: 0000000000000048 RBX: ffff89adb6441400 RCX: 0000000000000000^M > > > [ 1198.351839] RDX: 0000000000000000 RSI: ffff89adbaa97800 RDI: ffff89adbaa97800^M > > > [ 1198.354572] RBP: ffff89ada7584300 R08: 0000000000000417 R09: 0000000000000057^M > > > [ 1198.357150] R10: 0000000000000001 R11: ffff982e40710aa5 R12: ffff89adbaaae598^M > > > [ 1198.359067] R13: ffffe7bc819d6108 R14: ffffe7bc819d6100 R15: ffff89adb6442280^M > > > [ 1198.360975] FS: 0000000000000000(0000) GS:ffff89adbaa80000(0000) knlGS:0000000000000000^M > > > [ 1198.363202] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033^M > > > [ 1198.365986] CR2: 000055f6a3811318 CR3: 000000017adca005 CR4: 0000000000770ee0^M > > > [ 1198.368679] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000^M > > > [ 1198.371386] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400^M > > > [ 1198.374203] PKRU: 55555554^M > > > [ 1198.375174] Call Trace:^M > > > [ 1198.376165] <IRQ>^M > > > [ 1198.376908] ___cache_free+0x56d/0x770^M > > > [ 1198.378355] ? kmem_freepages+0xa0/0xf0^M > > > [ 1198.379814] kfree+0x91/0x120^M > > > [ 1198.382121] kmem_freepages+0xa0/0xf0^M > > > [ 1198.383474] slab_destroy+0x9f/0x120^M > > > [ 1198.384779] slabs_destroy+0x6d/0x90^M > > > [ 1198.386110] ___cache_free+0x632/0x770^M > > > [ 1198.387547] ? kmem_freepages+0xa0/0xf0^M > > > [ 1198.389016] kfree+0x91/0x120^M > > > [ 1198.390160] kmem_freepages+0xa0/0xf0^M > > > [ 1198.391551] slab_destroy+0x9f/0x120^M > > > [ 1198.392964] slabs_destroy+0x6d/0x90^M > > > [ 1198.394439] ___cache_free+0x632/0x770^M > > > [ 1198.395896] kmem_cache_free.part.75+0x19/0x70^M > > > [ 1198.397791] rcu_core+0x1eb/0x6b0^M > > > [ 1198.399829] ? ktime_get+0x37/0xa0^M > > > [ 1198.401343] __do_softirq+0xdf/0x2c5^M > > > [ 1198.403010] asm_call_on_stack+0x12/0x20^M > > > [ 1198.404847] </IRQ>^M > > > [ 1198.405799] do_softirq_own_stack+0x39/0x50^M > > > [ 1198.407621] irq_exit_rcu+0x97/0xa0^M > > > [ 1198.409127] sysvec_apic_timer_interrupt+0x2c/0x80^M > > > [ 1198.410608] asm_sysvec_apic_timer_interrupt+0x12/0x20^M > > > [ 1198.411883] RIP: 0010:default_idle+0x13/0x20^M > > > [ 1198.412994] Code: 89 44 24 20 48 83 c0 22 48 89 44 24 28 eb c7 e8 03 93 ff ff cc cc cc 0f 1f 44 00 00 e9 07 00 00 00 0f 00 2d 11 ec 55 00 fb f4 <c3> 66 66 2e 0f 1f 84 00 00 00 00 00 90 0f 1f 44 00 00 65 48 8b 04^M > > > > Hmm, so that this looks like some kind of RCU involvement? Some kind > > of object that had been scheduled to be freed via RCU, but then got > > freed before RCU cleanup happened? > > > > The question then is what subsystem the object involved came from. > > Right now, I don't get time to investigate further. It shouldn't be > hard to locate where the 192 slab allocation is from, together with RCU > involved. > > BTW, the double free is triggered by the following change on your > config: > > - disable lockdep > - disable kmemleak > - enable PAGE_POISONING oops, double free is captured by enabling CONFIG_DEBUG_SLAB instead of PAGE_POISONING, looks it is triggered reliably too. Thanks, Ming
