From c3668865c6496bacec56c7779acc915a64671540 Mon Sep 17 00:00:00 2001 From: Andreas Dilger Date: Wed, 7 Jun 2017 17:54:56 -0600 Subject: [PATCH] LU-4761 tests: clean up spurious messages and files Reduce spurious messages that appear in the test and console logs that are not useful for debugging, and just clutter things up. Clean up a few files left over from tests. Signed-off-by: Andreas Dilger Change-Id: Ie17888a8f9c5864530dcb455a0cd4e51f83ebbe5 Reviewed-on: https://review.whamcloud.com/29012 Tested-by: Jenkins Tested-by: Maloo Reviewed-by: Jian Yu Reviewed-by: Mike Pershin Reviewed-by: James Nunez Reviewed-by: Oleg Drokin --- lustre/mdt/mdt_xattr.c | 21 ++++++++++++--------- lustre/ptlrpc/client.c | 50 +++++++++++++++++++++++++++++--------------------- lustre/tests/sanity.sh | 30 ++++++++++++++++++++---------- 3 files changed, 61 insertions(+), 40 deletions(-) diff --git a/lustre/mdt/mdt_xattr.c b/lustre/mdt/mdt_xattr.c index 872cb77..c878041 100644 --- a/lustre/mdt/mdt_xattr.c +++ b/lustre/mdt/mdt_xattr.c @@ -71,14 +71,16 @@ static int mdt_getxattr_pack_reply(struct mdt_thread_info * info) !strncmp(xattr_name, user_string, sizeof(user_string) - 1)) RETURN(-EOPNOTSUPP); - size = mo_xattr_get(info->mti_env, - mdt_object_child(info->mti_object), - &LU_BUF_NULL, xattr_name); - } else if (valid == OBD_MD_FLXATTRLS) { - size = mo_xattr_list(info->mti_env, - mdt_object_child(info->mti_object), - &LU_BUF_NULL); + size = mo_xattr_get(info->mti_env, + mdt_object_child(info->mti_object), + &LU_BUF_NULL, xattr_name); + } else if (valid == OBD_MD_FLXATTRLS) { + xattr_name = "list"; + size = mo_xattr_list(info->mti_env, + mdt_object_child(info->mti_object), + &LU_BUF_NULL); } else if (valid == OBD_MD_FLXATTRALL) { + xattr_name = "all"; /* N.B. eadatasize = 0 is not valid for FLXATTRALL */ /* We could calculate accurate sizes, but this would * introduce a lot of overhead, let's do it later... */ @@ -94,8 +96,9 @@ static int mdt_getxattr_pack_reply(struct mdt_thread_info * info) if (size == -ENODATA) { size = 0; } else if (size < 0) { - if (size != -EOPNOTSUPP) - CERROR("Error geting EA size: %d\n", size); + if (size != -EOPNOTSUPP && size != -ENOENT) + CERROR("%s: error geting EA size for '%s': rc = %d\n", + mdt_obd_name(info->mti_mdt), xattr_name, size); RETURN(size); } diff --git a/lustre/ptlrpc/client.c b/lustre/ptlrpc/client.c index 1c05e76..e145ea3 100644 --- a/lustre/ptlrpc/client.c +++ b/lustre/ptlrpc/client.c @@ -1155,17 +1155,19 @@ static int ptlrpc_import_delay_req(struct obd_import *imp, LASSERT (status != NULL); *status = 0; - if (req->rq_ctx_init || req->rq_ctx_fini) { - /* always allow ctx init/fini rpc go through */ - } else if (imp->imp_state == LUSTRE_IMP_NEW) { - DEBUG_REQ(D_ERROR, req, "Uninitialized import."); - *status = -EIO; + if (req->rq_ctx_init || req->rq_ctx_fini) { + /* always allow ctx init/fini rpc go through */ + } else if (imp->imp_state == LUSTRE_IMP_NEW) { + DEBUG_REQ(D_ERROR, req, "Uninitialized import."); + *status = -EIO; } else if (imp->imp_state == LUSTRE_IMP_CLOSED) { - /* pings may safely race with umount */ - DEBUG_REQ(lustre_msg_get_opc(req->rq_reqmsg) == OBD_PING ? + unsigned int opc = lustre_msg_get_opc(req->rq_reqmsg); + + /* pings or MDS-equivalent STATFS may safely race with umount */ + DEBUG_REQ((opc == OBD_PING || opc == OST_STATFS) ? D_HA : D_ERROR, req, "IMP_CLOSED "); *status = -EIO; - } else if (ptlrpc_send_limit_expired(req)) { + } else if (ptlrpc_send_limit_expired(req)) { /* probably doesn't need to be a D_ERROR after initial testing*/ DEBUG_REQ(D_HA, req, "send limit expired "); *status = -ETIMEDOUT; @@ -1213,16 +1215,12 @@ static int ptlrpc_import_delay_req(struct obd_import *imp, * \retval false if no message should be printed * \retval true if console message should be printed */ -static bool ptlrpc_console_allow(struct ptlrpc_request *req) +static bool ptlrpc_console_allow(struct ptlrpc_request *req, __u32 opc, int err) { - __u32 opc; - LASSERT(req->rq_reqmsg != NULL); - opc = lustre_msg_get_opc(req->rq_reqmsg); /* Suppress particular reconnect errors which are to be expected. */ if (opc == OST_CONNECT || opc == MDS_CONNECT || opc == MGS_CONNECT) { - int err; /* Suppress timed out reconnect requests */ if (lustre_handle_is_used(&req->rq_import->imp_remote_handle) || @@ -1232,12 +1230,20 @@ static bool ptlrpc_console_allow(struct ptlrpc_request *req) /* Suppress most unavailable/again reconnect requests, but * print occasionally so it is clear client is trying to * connect to a server where no target is running. */ - err = lustre_msg_get_status(req->rq_repmsg); if ((err == -ENODEV || err == -EAGAIN) && req->rq_import->imp_conn_cnt % 30 != 20) return false; } + if (opc == LDLM_ENQUEUE && err == -EAGAIN) + /* -EAGAIN is normal when using POSIX flocks */ + return false; + + if (opc == OBD_PING && (err == -ENODEV || err == -ENOTCONN) && + (req->rq_xid & 0xf) != 10) + /* Suppress most ping requests, they may fail occasionally */ + return false; + return true; } @@ -1256,9 +1262,7 @@ static int ptlrpc_check_status(struct ptlrpc_request *req) lnet_nid_t nid = imp->imp_connection->c_peer.nid; __u32 opc = lustre_msg_get_opc(req->rq_reqmsg); - /* -EAGAIN is normal when using POSIX flocks */ - if (ptlrpc_console_allow(req) && - !(opc == LDLM_ENQUEUE && err == -EAGAIN)) + if (ptlrpc_console_allow(req, opc, err)) LCONSOLE_ERROR_MSG(0x11, "%s: operation %s to node %s " "failed: rc = %d\n", imp->imp_obd->obd_name, @@ -2097,6 +2101,7 @@ EXPORT_SYMBOL(ptlrpc_check_set); int ptlrpc_expire_one_request(struct ptlrpc_request *req, int async_unlink) { struct obd_import *imp = req->rq_import; + unsigned int debug_mask = D_RPCTRACE; int rc = 0; ENTRY; @@ -2104,12 +2109,15 @@ int ptlrpc_expire_one_request(struct ptlrpc_request *req, int async_unlink) req->rq_timedout = 1; spin_unlock(&req->rq_lock); - DEBUG_REQ(D_WARNING, req, "Request sent has %s: [sent %lld/real %lld]", - req->rq_net_err ? "failed due to network error" : - ((req->rq_real_sent == 0 || + if (ptlrpc_console_allow(req, lustre_msg_get_opc(req->rq_reqmsg), + lustre_msg_get_status(req->rq_reqmsg))) + debug_mask = D_WARNING; + DEBUG_REQ(debug_mask, req, "Request sent has %s: [sent %lld/real %lld]", + req->rq_net_err ? "failed due to network error" : + ((req->rq_real_sent == 0 || req->rq_real_sent < req->rq_sent || req->rq_real_sent >= req->rq_deadline) ? - "timed out for sent delay" : "timed out for slow reply"), + "timed out for sent delay" : "timed out for slow reply"), (s64)req->rq_sent, (s64)req->rq_real_sent); if (imp != NULL && obd_debug_peer_on_timeout) diff --git a/lustre/tests/sanity.sh b/lustre/tests/sanity.sh index 171b60e..0c8b657 100755 --- a/lustre/tests/sanity.sh +++ b/lustre/tests/sanity.sh @@ -1674,7 +1674,8 @@ test_27u() { # bug 4900 unlinkmany $DIR/$tdir/t- 1000 trap 0 [[ $OBJS -gt 0 ]] && - error "$OBJS objects created on OST-0. See $TLOG" || pass + error "$OBJS objects created on OST-0. See $TLOG" || + rm -f $TLOG } run_test 27u "skip object creation on OSC w/o objects" @@ -3839,6 +3840,7 @@ test_43a() { cp -p multiop $DIR/$tdir/multiop MULTIOP_PROG=$DIR/$tdir/multiop multiop_bg_pause $TMP/$tfile.junk O_c || error "multiop open $TMP/$tfile.junk failed" + rm $TMP/$tfile.junk # delete junk file on close (not part of test) MULTIOP_PID=$! $MULTIOP $DIR/$tdir/multiop Oc && error "expected error, got success" kill -USR1 $MULTIOP_PID || error "kill -USR1 PID $MULTIOP_PID failed" @@ -3853,6 +3855,7 @@ test_43b() { cp -p multiop $DIR/$tdir/multiop MULTIOP_PROG=$DIR/$tdir/multiop multiop_bg_pause $TMP/$tfile.junk O_c || error "multiop open $TMP/$tfile.junk failed" + rm $TMP/$tfile.junk # delete junk file on close (not part of test) MULTIOP_PID=$! $TRUNCATE $DIR/$tdir/multiop 0 && error "expected error, got success" kill -USR1 $MULTIOP_PID || error "kill -USR1 PID $MULTIOP_PID failed" @@ -11111,9 +11114,8 @@ test_156() { log "cache hits:: before: $BEFORE, after: $AFTER" fi - rm -f $file restore_lustre_params < $p - rm -f $p + rm -f $p $file } run_test 156 "Verification of tunables" @@ -14299,6 +14301,14 @@ test_246() { # LU-7371 } run_test 246 "Read file of size 4095 should return right length" +cleanup_247() { + local submount=$1 + + trap 0 + umount_client $submount + rmdir $submount +} + test_247a() { lctl get_param -n mdc.$FSNAME-MDT0000*.import | grep -q subtree || @@ -14310,11 +14320,11 @@ test_247a() { mkdir -p $submount || error "mkdir $submount failed" FILESET="$FILESET/$tdir" mount_client $submount || error "mount $submount failed" + trap "cleanup_247 $submount" EXIT echo foo > $submount/$tfile || error "write $submount/$tfile failed" [ $(cat $MOUNT/$tdir/$tfile) = "foo" ] || error "read $MOUNT/$tdir/$tfile failed" - umount_client $submount || error "umount $submount failed" - rmdir $submount + cleanup_247 $submount } run_test 247a "mount subdir as fileset" @@ -14341,12 +14351,12 @@ test_247c() { mkdir -p $MOUNT/$tdir/dir1 mkdir -p $submount || error "mkdir $submount failed" + trap "cleanup_247 $submount" EXIT FILESET="$FILESET/$tdir" mount_client $submount || error "mount $submount failed" local fid=$($LFS path2fid $MOUNT/) $LFS fid2path $submount $fid && error "fid2path should fail" - umount_client $submount || error "umount $submount failed" - rmdir $submount + cleanup_247 $submount } run_test 247c "running fid2path outside root" @@ -14360,10 +14370,10 @@ test_247d() { mkdir -p $submount || error "mkdir $submount failed" FILESET="$FILESET/$tdir" mount_client $submount || error "mount $submount failed" + trap "cleanup_247 $submount" EXIT local fid=$($LFS path2fid $submount/dir1) $LFS fid2path $submount $fid || error "fid2path should succeed" - umount_client $submount || error "umount $submount failed" - rmdir $submount + cleanup_247 $submount } run_test 247d "running fid2path inside root" @@ -16780,7 +16790,7 @@ test_403() { wait - [ `cat $tfile` -gt 0 ] || error "wrong nlink count: `cat $tfile`" + [ $(cat $tfile) -gt 0 ] || error "wrong nlink count: $(cat $tfile)" rm -f $tfile $file1 $file2 } -- 1.8.3.1