Details
-
Bug
-
Resolution: Fixed
-
Blocker
-
Lustre 2.3.0, Lustre 2.4.0
-
None
-
CONFIG_DEBUG_SLAB=y
-
3
-
4237
Description
Lustre: DEBUG MARKER: == sanity test 103: acl test ========================================================================= 19:57:07 (1346774227)
/work/lustre/head/clean/lustre/utils/l_getidentity
Slab corruption (Tainted: P --------------- ): size-2048 start=dac6c470, len=2048
Redzone: 0x9f911029d74e35b/0x9f911029d74e35b.
Last user: [<dff39e58>](cfs_free+0x8/0x10 [libcfs])
310: 02 00 00 00 01 00 07 00 ff ff ff ff 02 00 05 00
320: 01 00 00 00 02 00 07 00 02 00 00 00 04 00 07 00
330: ff ff ff ff 10 00 07 00 ff ff ff ff 20 00 05 00
340: ff ff ff ff 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b
Next obj: start=dac6cc88, len=2048
Redzone: 0x9f911029d74e35b/0x9f911029d74e35b.
Last user: [<dff39e58>](cfs_free+0x8/0x10 [libcfs])
000: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b
010: 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b 6b
02000000:00000010:1.0:1346774231.327841:1804:3373:0:(sec_null.c:217:null_alloc_repbuf()) kmalloced 'req->rq_repbuf': 2048 at dac6c470.
...
02000000:00000010:1.0:1346774231.328361:836:3373:0:(sec_null.c:231:null_free_repbuf()) kfreed 'req->rq_repbuf': 2048 at dac6c470.
Attachments
Issue Links
Activity
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.
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.
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.
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.
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".
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.
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).
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 ]---
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.
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, 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