|
Keith is going to try and reproduce this with a debug kernel
|
|
Are there more logs from the rest of the systems? Is there anything special needed to reproduce this?
|
|
I'm able to reproduce this almost 100% with REFORMAT=y ONLY=103 sh sanity.sh, within single vbox instance.
|
|
I know in the past, Oleg, Johann, and I have wanted to run early development kernels with various debug options enabled for all kernel builds, so that this kind of problem can be flushed out when patches land instead of only at users who run these debug kernels, or hitting silent corruption problems. This previously was suggested by Johann in TT-359, but I think it could be done with a patch to the kernel config options during the development cycle instead of via the test environment (which would need more effort/complexity).
I think since we are early in the 2.4 release cycle that it makes sense to enable these config options for all our server kernels (so they will be seen for servers and clients running the server kernel). We can leave this as a blocker bug for the 2.4 release to remember to revert the debug kernel config changes.
Given the relatively small number of patches that have landed on master compared to 2.3, it probably also makes sense to submit a patch to b2_3 to enable CONFIG_DEBUG_SLAB, CONFIG_DEBUG_SPINLOCK and possibly some others, with:
to see if there is a similar failure for b2_3.
|
|
probably it'd make sense to add a trivial (dmesg|grep 'Slab corruption' && error) to t-f so that we don't miss it.
|
|
I submitted a few config changes for b2_3 as suggested. http://review.whamcloud.com/3875 .
I have been able to get some local testing done today. I tried an older 2.2.59 code base (I had it setup on one of my build servers) and I don't seem to see the problem there but I do see it with Master. I will work to narrow down the window of possible changes. Sorting out if b2_3 is effected is my next step.
|
|
My config test didn't make it though build on the first pass but Yu has a very nice patch/test here I am watching http://review.whamcloud.com/#change,3876
|
|
Hi Keith,
By using the build http://build.whamcloud.com/job/lustre-reviews/8904/ in http://review.whamcloud.com/#change,3876, I can manually reproduce the slab corruption issue on RHEL6 distro by only running sanity test 103:
https://maloo.whamcloud.com/test_sets/2c479ade-f7d3-11e1-8b95-52540035b04c
The autotest run for the above build skipped sanity test 103 because it's in the EXCEPT_SLOW list. I'm updating the commit message to add SLOW=yes into the test parameters.
|
|
Hi Keith,
FYI, with the build for patch set 5 of http://review.whamcloud.com/#change,3876, I reproduced the issue with PTLDEBUG=-1 manually:
https://maloo.whamcloud.com/test_sets/59a5ca46-f832-11e1-b114-52540035b04c
|
|
If there are no obvious sources of this corruption, it probably makes sense to submit this test patch as several separate changes, each based on one of the recent 2.2.* tags, to see if we can isolate when this corruption started. After that, it is hopefully possible to do a (manual?) git-bisect to find which patch is the culprit, or at least narrow down the range of patches that need to be examined manually. It is also important to check in each of the failure cases what node type the corruption is seen on (MDS, OSS, client), since that will also reduce the number of changes which might have introduced the problem.
It would make sense to include a check for the LU-1844 list_add/list_del corruption messages as well, since I suspect that is also a sign of random memory corruption.
|
|
I have started a git bisect to narrow down the code change but I fear it is not realiable data. I am not sure what has happened on my local vms (I shuffled some vms around yesterday) but I am no longer able to reproduce the core issue. I am running Lustre: 2.3.50 (from Master) with kernel-2.6.32-279.5.2 an not triggering the issue. I am moving back to kernel-2.6.32-279.1.1 (confirmed failed with Yu's test run) to see if the issue reappears.
I will update when I know more.
|
|
Per the above test report, the slab corruption issue occurred only on the MDS (fat-intel-2):
|
|
Moving kernels does not seem to reproduce the issue so it is not a lead. I am going to try some client nodes tomorrow. I saw the error on the MDS as well on my initial Master run but have not see it since.
|
|
I acquired some torro nods today and am starting to setup. My mds vm crashed while running " REFORMAT=y ONLY=103 sh sanity.sh", it took about 30 hours to trigger). This could be the bad cfs_free path that is corrupting the slab.
I will try and attach the whole dmesg.
This was master + kernel-2.6.32-279 on the MDS vm node.
|
|
Keith local vm MDS panic -v1 dmesg
|
|
Hi Keith,
I created several test patches per the following comments from Andreas:
If there are no obvious sources of this corruption, it probably makes sense to submit this test patch as several separate changes, each based on one of the recent 2.2.* tags, to see if we can isolate when this corruption started.
Patch on tag 2.2.94: http://review.whamcloud.com/#change,3921
Patch on tag 2.3.50: http://review.whamcloud.com/#change,3918
Patch on tag 2.2.93: http://review.whamcloud.com/#change,3919
Patch on tag 2.2.92: http://review.whamcloud.com/#change,3920
Hope we can isolate the issue.
|
|
Keith, can you please fix Yu Jian's patches that hit build failures.
The 2.3.50 patch failed to build due to built-in version checks, so it needs to be rebased one patch later (git hash 388111848489ef99b1fa31ce8fef255ab9c08e84). I haven't investigated the other failure, but hopefully it is similarly trivial. Please get to this ASAP so that the testing can be started on these patches, and hopefully we can isolate this serious defect more quickly.
|
|
Ok, I enabled debug pagealloc and caught the offender I think:
[ 3201.251050] Lustre: 9532:0:(mdt_lproc.c:418:lprocfs_wr_identity_upcall()) lus
tre-MDT0000: identity upcall set to /home/green/git/lustre-release/lustre/utils/
l_getidentity
[ 3204.127208] BUG: unable to handle kernel paging request at ffff88021851ab48
[ 3204.129164] IP: [<ffffffff811d9dd8>] posix_acl_to_xattr+0x28/0x80
[ 3204.130098] PGD 1a26063 PUD 2766067 PMD 2829067 PTE 800000021851a160
[ 3204.130673] Oops: 0002 [#1] SMP DEBUG_PAGEALLOC
[ 3204.130673] last sysfs file: /sys/devices/system/cpu/possible
[ 3204.130673] CPU 1
[ 3204.130673] Modules linked in: lustre obdfilter ost cmm mdt osd_ldiskfs fsfil
t_ldiskfs ldiskfs mdd mds mgs lquota obdecho mgc lov osc mdc lmv fid fld ptlrpc obdclass lvfs ksocklnd lnet libcfs ext2 exportfs jbd sha512_generic sha256_gener
ic sunrpc ipv6 microcode virtio_balloon virtio_net i2c_piix4 i2c_core ext4 mbcac
he jbd2 virtio_blk virtio_pci virtio_ring virtio pata_acpi ata_generic ata_piix
dm_mirror dm_region_hash dm_log dm_mod [last unloaded: libcfs]
[ 3204.130673]
[ 3204.130673] Pid: 8603, comm: mdt00_001 Not tainted 2.6.32-debug #3 Bochs Boch
s
[ 3204.130673] RIP: 0010:[<ffffffff811d9dd8>] [<ffffffff811d9dd8>] posix_acl_to
_xattr+0x28/0x80
[ 3204.130673] RSP: 0018:ffff88027a9459d0 EFLAGS: 00010287
[ 3204.130673] RAX: 0000000000000034 RBX: ffff88021851ab48 RCX: 0000000000000034
[ 3204.130673] RDX: 0000000000000060 RSI: ffff88021851ab48 RDI: ffff88023a694e50
[ 3204.130673] RBP: ffff88027a9459d0 R08: ffffffffa055f3cd R09: ffffffffa05f8e36
[ 3204.130673] R10: 0000000000000000 R11: ffffffffa05fee98 R12: ffff88023a694e50
[ 3204.130673] R13: 0000000000000060 R14: ffffffffa055f3cd R15: ffff8802470b5b98
[ 3204.130673] FS: 00007fcc8f724700(0000) GS:ffff880028240000(0000) knlGS:0000000000000000
[ 3204.130673] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 3204.130673] CR2: ffff88021851ab48 CR3: 00000002653cb000 CR4: 00000000000006e0
[ 3204.130673] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 3204.130673] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[ 3204.130673] Process mdt00_001 (pid: 8603, threadinfo ffff88027a944000, task ffff88027a942540)
[ 3204.130673] Stack:
[ 3204.130673] ffff88027a945a10 ffffffffa05ac598 ffff88027a9459f0 ffffffffa067b661
[ 3204.130673] <d> 0000000000000010 ffff880222a70ef0 ffff880202a25bb8 ffff88027848b928
[ 3204.130673] <d> ffff88027a945a20 ffffffffa05ac612 ffff88027a945a30 ffffffff811a0147
[ 3204.130673] Call Trace:
[ 3204.130673] [<ffffffffa05ac598>] ldiskfs_xattr_get_acl+0x78/0xa0 [ldiskfs]
[ 3204.130673] [<ffffffffa067b661>] ? libcfs_debug_msg+0x41/0x50 [libcfs]
[ 3204.130673] [<ffffffffa05ac612>] ldiskfs_xattr_get_acl_access+0x22/0x30 [ldiskfs]
[ 3204.130673] [<ffffffff811a0147>] generic_getxattr+0x87/0x90
[ 3204.130673] [<ffffffffa074af64>] osd_xattr_get+0x284/0x360 [osd_ldiskfs]
[ 3204.130673] [<ffffffffa05356d0>] mdd_attr_set+0x15b0/0x2250 [mdd]
[ 3204.130673] [<ffffffffa067b661>] ? libcfs_debug_msg+0x41/0x50 [libcfs]
[ 3204.130673] [<ffffffffa0888a26>] cml_attr_set+0x66/0x1a0 [cmm]
[ 3204.130673] [<ffffffffa07bc768>] mdt_attr_set+0x2a8/0x590 [mdt]
[ 3204.130673] [<ffffffffa07bd096>] mdt_reint_setattr+0x646/0x13f0 [mdt]
[ 3204.130673] [<ffffffffa067b661>] ? libcfs_debug_msg+0x41/0x50 [libcfs]
[ 3204.130673] [<ffffffffa07b6081>] mdt_reint_rec+0x41/0xe0 [mdt]
[ 3204.130673] [<ffffffffa07af42a>] mdt_reint_internal+0x50a/0x810 [mdt]
[ 3204.130673] [<ffffffffa07af774>] mdt_reint+0x44/0xe0 [mdt]
[ 3204.130673] [<ffffffffa07a1d42>] mdt_handle_common+0x922/0x1740 [mdt]
[ 3204.130673] [<ffffffffa07a2c35>] mdt_regular_handle+0x15/0x20 [mdt]
[ 3204.130673] [<ffffffffa0f7486f>] ptlrpc_server_handle_request+0x44f/0xee0 [ptlrpc]
[ 3204.130673] [<ffffffffa066b66e>] ? cfs_timer_arm+0xe/0x10 [libcfs]
[ 3204.130673] [<ffffffffa0f6d711>] ? ptlrpc_wait_event+0xb1/0x2a0 [ptlrpc]
[ 3204.130673] [<ffffffffa067b661>] ? libcfs_debug_msg+0x41/0x50 [libcfs]
[ 3204.130673] [<ffffffff81051f73>] ? __wake_up+0x53/0x70
[ 3204.130673] [<ffffffffa0f773de>] ptlrpc_main+0xaee/0x1800 [ptlrpc]
[ 3204.130673] [<ffffffffa0f768f0>] ? ptlrpc_main+0x0/0x1800 [ptlrpc]
[ 3204.130673] [<ffffffff8100c14a>] child_rip+0xa/0x20
[ 3204.130673] [<ffffffffa0f768f0>] ? ptlrpc_main+0x0/0x1800 [ptlrpc]
[ 3204.130673] [<ffffffffa0f768f0>] ? ptlrpc_main+0x0/0x1800 [ptlrpc]
[ 3204.130673] [<ffffffff8100c140>] ? child_rip+0x0/0x20
[ 3204.130673] Code: c3 90 90 55 48 89 e5 0f 1f 44 00 00 48 63 47 04 48 85 f6 8d 04 c5 04 00 00 00 75 07 c9 c3 0f 1f 44 00 00 48 63 c8 48 39 d1 77 48 <c7> 06 02 00 00 00 8b 57 04 85 d2 74 e4 48 83 c6 04 31 d2 0f 1f
[ 3204.130673] RIP [<ffffffff811d9dd8>] posix_acl_to_xattr+0x28/0x80
[ 3204.130673] RSP <ffff88027a9459d0>
[ 3204.130673] CR2: ffff88021851ab48
[ 3204.130673] ---[ end trace f9aa2ef75b2f20bf ]---
|
|
Ok, my current theory is we have a problem coming from patch in LU-998.
mdd_declare_attr_set:
if (ma->ma_attr.la_valid & LA_MODE) {
mdd_read_lock(env, obj, MOR_TGT_CHILD);
rc = mdo_xattr_get(env, obj, buf, XATTR_NAME_ACL_ACCESS,
BYPASS_CAPA);
mdd_read_unlock(env, obj);
here we'll just use whatever happens to be in buf which sometimes ends up as garbage.
I am not exactly clear on how it's supposed to be used, but it looks like the buffer should be reinitialized every time it's about to be used afresh (frankly I am not even sure why is it needed because it seems to be always duplicated in some local vars that we pass around). Other cases in that same function do initialize the buffer address.
My reading of the code is such that we are just trying to make sure the xattrs exist at all, but if the buf happens to contain some pointer from before and declared size is big enough to fit the xattr, we read them to the buffer overwriting whatever important data was there (and it seems it's frequently points to freed and then possibly reallocated data too).
The fix for this particular problem is to probably pass in &LU_BUF_NULL instead of buf argument. (patch at http://review.whamcloud.com/3928 and seems to be holding well in my testing)
The wider question if the buf is supposed to point to freed memory at any time still remains to be open and I need somebody's help to determine this.
If that is not supposed to happen, we can track down offending user (and I imagine it's probably not super valid because occasionally on shutdown we do try to free that memory that buffer points to and if it's invalid, that's a problem, even though nobody has ever seen this before for some reason).
|
|
Oleg are you testing with DEBUG_SLAB as well? child_rip is the only thing that seems common there is no mention of the slab code path and cfs_free in your back trace.
Can you confirm that the slab errors have gone away with your patch? I have put your patch in my test queue on the bisect setup as well.
|
|
I have started a fresh build/bisect setup with client-7 client-17 client-18. I am able to reliability re-create here. This is the exact build that does not trigger on my system and the same config changes at Yu's. I fear that running on a random setups (via autotest) may lead to false negatives since some setups produce the error and some don't. I will kick the builds along but I would not trust any single run passes as "Not Broken".
|
|
Keith, PAGEALLOC debug is a more powerful (and slow) kernel feature to track random memory writes. What it does is when you free a page instead of merely writing it with some poison value to check later (what you are hitting, and once hit - no way to know who made the write) it actually unmaps the page from address space, so when the offender comes to do the write, the page is not there and we get the nice oops pointing at the red-handed writer to the place they are not supposed to be writing.
|
|
Oleg I am familiar with PAGEALLOC. I am just wondering if it is a separate issue or not. I didn't get a chance to test your patch but I will do it first thing tomorrow.
On my nodes can produce the issue I was able to test 2.2.59 and I don't see the issue but lu-998 code should be present it the release.
I am building on the client nodes now to speed thing up I hope tomorrow I can get thing greatly narrowed down if Oleg's patch is not the root issue.
Sorry I didn't get a change to push Yu's build errors yet.
|
|
Hi Keith,
I submitted a patch which contained Oleg's patch and enabled the kernel debug options to verify whether the issue is resolved or not on master branch: http://review.whamcloud.com/3936.
|
|
Keith, ok. Well, the original issue my patch fixes is there since long ago, it might have been hidden to because nobody was leaving incorrect pointers in the mti_info buf, and then later somebody started to do it and that's why everything started to fall apart lately.
Granted I did not try to go back all the way to see if I can reproduce it on just the original commit
|
|
I been running http://review.whamcloud.com/3928 with Master for a few hours now and I do not seem to be able to reproduce the errors. It looks to be the fix to me.
If Yu's latest build agrees I will cherry pick it to b2_3 and b2_2.
Thanks for finding this Oleg.
|
|
Don't create separate patches for other branches, please/ I'll cherry-pick this patch directly since that part of the code have not changed since landing.
|
I submitted a patch which contained Oleg's patch and enabled the kernel debug options to verify whether the issue is resolved or not on master branch: http://review.whamcloud.com/3936.
sanity test 103 passed without detecting slab corruption issue.
|
|
I have almost 24 hours of testing and still no recreation.
Oleg I will leave the cherry-pick to you.
|
|
Landed for 2.3 and 2.4
|
|
review-dne failed as:
|
Generated at Sat Feb 10 01:19:59 UTC 2024 using Jira 9.4.14#940014-sha1:734e6822bbf0d45eff9af51f82432957f73aa32c.
mdt-serial.log