From: Bobi Jam Date: Sat, 9 Jun 2012 10:12:51 +0000 (+0800) Subject: LU-988 ost: add debugging for inode timestamps X-Git-Tag: 2.2.57~5 X-Git-Url: https://git.whamcloud.com/?p=fs%2Flustre-release.git;a=commitdiff_plain;h=be98db71e3701fcfa37cac37882eabe9c9910a76 LU-988 ost: add debugging for inode timestamps Intermittent test failures for sanity.sh test_39j are showing the inode timestamps going backward. Add internal debugging to track the LVB timestamps to see where the old timestamps are coming from, to determine if this is a problem with the VM environment being used for testing, or if it is a genuine problem in the Lustre code. Signed-off-by: Bobi Jam Change-Id: I590d8b28b7a37010af6a43d329917022b840d074 Reviewed-on: http://review.whamcloud.com/3069 Tested-by: Hudson Tested-by: Maloo Reviewed-by: Lai Siyao Reviewed-by: Fan Yong Reviewed-by: Andreas Dilger --- diff --git a/lustre/lov/lov_merge.c b/lustre/lov/lov_merge.c index f74ff0d..bb29f48 100644 --- a/lustre/lov/lov_merge.c +++ b/lustre/lov/lov_merge.c @@ -67,6 +67,11 @@ int lov_merge_lvb_kms(struct lov_stripe_md *lsm, LASSERT(lsm->lsm_lock_owner == cfs_curproc_pid()); #endif + CDEBUG(D_INODE, "MDT FID "DFID" initial value: s="LPU64" m="LPU64 + " a="LPU64" c="LPU64" b="LPU64"\n", + lsm->lsm_object_seq, (__u32)lsm->lsm_object_id, + (__u32)(lsm->lsm_object_id >> 32), lvb->lvb_size, + lvb->lvb_mtime, lvb->lvb_atime, lvb->lvb_ctime, lvb->lvb_blocks); for (i = 0; i < lsm->lsm_stripe_count; i++) { struct lov_oinfo *loi = lsm->lsm_oinfo[i]; obd_size lov_size, tmpsize; @@ -99,8 +104,9 @@ int lov_merge_lvb_kms(struct lov_stripe_md *lsm, " a="LPU64" c="LPU64" b="LPU64"\n", lsm->lsm_object_seq, (__u32)lsm->lsm_object_id, (__u32)(lsm->lsm_object_id >> 32), loi->loi_ost_idx, - lvb->lvb_size, lvb->lvb_mtime, lvb->lvb_atime, - lvb->lvb_ctime, lvb->lvb_blocks); + loi->loi_lvb.lvb_size, loi->loi_lvb.lvb_mtime, + loi->loi_lvb.lvb_atime, loi->loi_lvb.lvb_ctime, + loi->loi_lvb.lvb_blocks); } *kms_place = kms; diff --git a/lustre/obdfilter/filter_io_26.c b/lustre/obdfilter/filter_io_26.c index 26fb2cff..6feac45 100644 --- a/lustre/obdfilter/filter_io_26.c +++ b/lustre/obdfilter/filter_io_26.c @@ -758,6 +758,11 @@ retry: iattr.ia_valid = save & ~(ATTR_UID | ATTR_GID); } + CDEBUG(D_INODE, "FID "DFID" to write: s="LPU64" m="LPU64" a="LPU64 + " c="LPU64" b="LPU64"\n", + oa->o_id, (__u32)oa->o_seq, (__u32)oa->o_seq, + oa->o_size, oa->o_mtime, oa->o_atime, oa->o_ctime, + oa->o_blocks); /* filter_direct_io drops i_mutex */ rc = filter_direct_io(OBD_BRW_WRITE, res->dentry, iobuf, exp, &iattr, oti, sync_journal_commit ? &wait_handle : NULL); @@ -772,6 +777,11 @@ retry: obdo_from_inode(oa, inode, (rc == 0 ? FILTER_VALID_FLAGS : 0) | OBD_MD_FLUID | OBD_MD_FLGID); + CDEBUG(D_INODE, "FID "DFID" after write: s="LPU64" m="LPU64" a="LPU64 + " c="LPU64" b="LPU64"\n", + oa->o_id, (__u32)oa->o_seq, (__u32)oa->o_seq, + oa->o_size, oa->o_mtime, oa->o_atime, oa->o_ctime, + oa->o_blocks); lquota_getflag(filter_quota_interface_ref, obd, oa); fsfilt_check_slow(obd, now, "direct_io"); diff --git a/lustre/tests/sanity.sh b/lustre/tests/sanity.sh index a008b0b..190f128 100644 --- a/lustre/tests/sanity.sh +++ b/lustre/tests/sanity.sh @@ -2426,8 +2426,7 @@ test_39i() { run_test 39i "write, rename, stat ==============================" test_39j() { - debugsave - lctl set_param debug=-1 + start_full_debug_logging touch $DIR1/$tfile sleep 1 @@ -2448,7 +2447,7 @@ test_39j() { cancel_lru_locks osc if [ $i = 0 ] ; then echo "repeat after cancel_lru_locks"; fi done - debugrestore + stop_full_debug_logging } run_test 39j "write, rename, close, stat ======================="