From 98d88213b8adde7cfa4a3b7aa1ff65e17e7e93a9 Mon Sep 17 00:00:00 2001 From: Fan Yong Date: Tue, 13 May 2014 22:13:59 +0800 Subject: [PATCH] LU-4610 lfsck: fix lfsck, osd-ldiskfs, osd-zfs debug messages Fix the debug subsystems for osd-ldiskfs, and osd-zfs to use S_OSD instead of S_MDS for easier debug message filtering, except osd_scrub.c which is using S_LFSCK instead of S_MDS. Do not print a D_LFSCK message in osd_otable_it_preload(), since this is being printed for every inode in the filesystem and fills the logs if D_LFSCK is enabled. Fix lfsck_pos_dump() to print the directory hash cookie in hex and fix up sanity-lfsck test_6a to be able to handle this. More D_LFSCK debug message for LFSCK check/repair processing. This is the first step for logging all the LFSCK changes. The next step will collect these LFSCK debug message and save them in some files automatically. Enable D_LFSCK debug by default. Signed-off-by: Fan Yong Signed-off-by: Andreas Dilger Change-Id: Iff3143f22d3c4750ebe95fbeba8883a325300c1e Reviewed-on: http://review.whamcloud.com/10579 Tested-by: Jenkins Tested-by: Maloo Reviewed-by: James Nunez --- libcfs/libcfs/debug.c | 2 +- lustre/lfsck/lfsck_bookmark.c | 37 ++- lustre/lfsck/lfsck_engine.c | 51 ++++- lustre/lfsck/lfsck_layout.c | 480 +++++++++++++++++++++++++-------------- lustre/lfsck/lfsck_lib.c | 77 ++----- lustre/lfsck/lfsck_namespace.c | 152 ++++++++----- lustre/ofd/ofd_io.c | 10 +- lustre/osd-ldiskfs/osd_handler.c | 83 ++++--- lustre/osd-ldiskfs/osd_lproc.c | 2 +- lustre/osd-ldiskfs/osd_oi.c | 2 +- lustre/osd-ldiskfs/osd_scrub.c | 120 +++++----- lustre/osd-zfs/osd_lproc.c | 2 +- lustre/tests/sanity-lfsck.sh | 6 +- 13 files changed, 611 insertions(+), 413 deletions(-) diff --git a/libcfs/libcfs/debug.c b/libcfs/libcfs/debug.c index 4384e7a..417a494 100644 --- a/libcfs/libcfs/debug.c +++ b/libcfs/libcfs/debug.c @@ -52,7 +52,7 @@ CFS_MODULE_PARM(libcfs_subsystem_debug, "i", int, 0644, EXPORT_SYMBOL(libcfs_subsystem_debug); unsigned int libcfs_debug = (D_CANTMASK | - D_NETERROR | D_HA | D_CONFIG | D_IOCTL); + D_NETERROR | D_HA | D_CONFIG | D_IOCTL | D_LFSCK); CFS_MODULE_PARM(libcfs_debug, "i", int, 0644, "Lustre kernel debug mask"); EXPORT_SYMBOL(libcfs_debug); diff --git a/lustre/lfsck/lfsck_bookmark.c b/lustre/lfsck/lfsck_bookmark.c index cf31418..0036522 100644 --- a/lustre/lfsck/lfsck_bookmark.c +++ b/lustre/lfsck/lfsck_bookmark.c @@ -80,9 +80,9 @@ static int lfsck_bookmark_load(const struct lu_env *env, lfsck_bookmark_le_to_cpu(bm, &lfsck->li_bookmark_disk); if (bm->lb_magic != LFSCK_BOOKMARK_MAGIC) { - CWARN("%s: invalid lfsck_bookmark magic %#x != %#x\n", - lfsck_lfsck2name(lfsck), bm->lb_magic, - LFSCK_BOOKMARK_MAGIC); + CDEBUG(D_LFSCK, "%s: invalid lfsck_bookmark magic " + "%#x != %#x\n", lfsck_lfsck2name(lfsck), + bm->lb_magic, LFSCK_BOOKMARK_MAGIC); /* Process it as new lfsck_bookmark. */ rc = -ENODATA; } @@ -91,8 +91,8 @@ static int lfsck_bookmark_load(const struct lu_env *env, /* return -ENODATA for empty lfsck_bookmark. */ rc = -ENODATA; else - CERROR("%s: fail to load lfsck_bookmark: " - "expected = %d, rc = %d\n", + CDEBUG(D_LFSCK, "%s: fail to load lfsck_bookmark, " + "expected = %d: rc = %d\n", lfsck_lfsck2name(lfsck), len, rc); } return rc; @@ -110,41 +110,33 @@ int lfsck_bookmark_store(const struct lu_env *env, struct lfsck_instance *lfsck) lfsck_bookmark_cpu_to_le(&lfsck->li_bookmark_disk, &lfsck->li_bookmark_ram); handle = dt_trans_create(env, lfsck->li_bottom); - if (IS_ERR(handle)) { - rc = PTR_ERR(handle); - CERROR("%s: fail to create trans for storing lfsck_bookmark: " - "rc = %d\n", lfsck_lfsck2name(lfsck), rc); - RETURN(rc); - } + if (IS_ERR(handle)) + GOTO(log, rc = PTR_ERR(handle)); rc = dt_declare_record_write(env, obj, lfsck_buf_get(env, &lfsck->li_bookmark_disk, len), 0, handle); - if (rc != 0) { - CERROR("%s: fail to declare trans for storing lfsck_bookmark: " - "rc = %d\n", lfsck_lfsck2name(lfsck), rc); + if (rc != 0) GOTO(out, rc); - } rc = dt_trans_start_local(env, lfsck->li_bottom, handle); - if (rc != 0) { - CERROR("%s: fail to start trans for storing lfsck_bookmark: " - "rc = %d\n", lfsck_lfsck2name(lfsck), rc); + if (rc != 0) GOTO(out, rc); - } rc = dt_record_write(env, obj, lfsck_buf_get(env, &lfsck->li_bookmark_disk, len), &pos, handle); - if (rc != 0) - CERROR("%s: fail to store lfsck_bookmark: expected = %d, " - "rc = %d\n", lfsck_lfsck2name(lfsck), len, rc); GOTO(out, rc); out: dt_trans_stop(env, lfsck->li_bottom, handle); + +log: + if (rc != 0) + CDEBUG(D_LFSCK, "%s: fail to store lfsck_bookmark: rc = %d\n", + lfsck_lfsck2name(lfsck), rc); return rc; } @@ -322,4 +314,3 @@ int lfsck_set_param(const struct lu_env *env, struct lfsck_instance *lfsck, return rc; } - diff --git a/lustre/lfsck/lfsck_engine.c b/lustre/lfsck/lfsck_engine.c index e31faf3..87b442d 100644 --- a/lustre/lfsck/lfsck_engine.c +++ b/lustre/lfsck/lfsck_engine.c @@ -155,8 +155,8 @@ static int lfsck_master_dir_engine(const struct lu_env *env, struct lfsck_instance *lfsck) { struct lfsck_thread_info *info = lfsck_env_info(env); - const struct dt_it_ops *iops = - &lfsck->li_obj_dir->do_index_ops->dio_it; + struct dt_object *dir = lfsck->li_obj_dir; + const struct dt_it_ops *iops = &dir->do_index_ops->dio_it; struct dt_it *di = lfsck->li_di_dir; struct lu_dirent *ent = &info->lti_ent; struct lu_fid *fid = &info->lti_fid; @@ -184,6 +184,11 @@ static int lfsck_master_dir_engine(const struct lu_env *env, lfsck->li_args_dir); lfsck_unpack_ent(ent, &lfsck->li_cookie_dir); if (rc != 0) { + CDEBUG(D_LFSCK, "%s: scan dir failed at rec(), " + "parent "DFID", cookie "LPX64": rc = %d\n", + lfsck_lfsck2name(lfsck), + PFID(lfsck_dto2fid(dir)), + lfsck->li_cookie_dir, rc); lfsck_fail(env, lfsck, true); if (bk->lb_param & LPF_FAILOUT) RETURN(rc); @@ -199,6 +204,12 @@ static int lfsck_master_dir_engine(const struct lu_env *env, if (child == NULL) { goto checkpoint; } else if (IS_ERR(child)) { + CDEBUG(D_LFSCK, "%s: scan dir failed at find target, " + "parent "DFID", child %.*s "DFID": rc = %d\n", + lfsck_lfsck2name(lfsck), + PFID(lfsck_dto2fid(dir)), + ent->lde_namelen, ent->lde_name, + PFID(&ent->lde_fid), rc); lfsck_fail(env, lfsck, true); if (bk->lb_param & LPF_FAILOUT) RETURN(PTR_ERR(child)); @@ -221,8 +232,14 @@ checkpoint: /* Rate control. */ lfsck_control_speed(lfsck); - if (unlikely(!thread_is_running(thread))) + if (unlikely(!thread_is_running(thread))) { + CDEBUG(D_LFSCK, "%s: scan dir exit for engine stop, " + "parent "DFID", cookie "LPX64"\n", + lfsck_lfsck2name(lfsck), + PFID(lfsck_dto2fid(dir)), + lfsck->li_cookie_dir); RETURN(0); + } if (OBD_FAIL_CHECK(OBD_FAIL_LFSCK_FATAL2)) { spin_lock(&lfsck->li_lock); @@ -286,6 +303,8 @@ static int lfsck_master_oit_engine(const struct lu_env *env, lfsck->li_new_scanned++; rc = iops->rec(env, di, (struct dt_rec *)fid, 0); if (rc != 0) { + CDEBUG(D_LFSCK, "%s: OIT scan failed at rec(): " + "rc = %d\n", lfsck_lfsck2name(lfsck), rc); lfsck_fail(env, lfsck, true); if (rc < 0 && bk->lb_param & LPF_FAILOUT) RETURN(rc); @@ -318,6 +337,10 @@ static int lfsck_master_oit_engine(const struct lu_env *env, if (target == NULL) { goto checkpoint; } else if (IS_ERR(target)) { + CDEBUG(D_LFSCK, "%s: OIT scan failed at find target " + DFID", cookie "LPU64": rc = %d\n", + lfsck_lfsck2name(lfsck), PFID(fid), + iops->store(env, di), rc); lfsck_fail(env, lfsck, true); if (bk->lb_param & LPF_FAILOUT) RETURN(PTR_ERR(target)); @@ -328,8 +351,14 @@ static int lfsck_master_oit_engine(const struct lu_env *env, /* XXX: Currently, skip remote object, the consistency for * remote object will be processed in LFSCK phase III. */ if (dt_object_exists(target) && !dt_object_remote(target)) { - if (update_lma) + if (update_lma) { rc = lfsck_update_lma(env, lfsck, target); + if (rc != 0) + CDEBUG(D_LFSCK, "%s: fail to update " + "LMA for "DFID": rc = %d\n", + lfsck_lfsck2name(lfsck), + PFID(lfsck_dto2fid(target)), rc); + } if (rc == 0) rc = lfsck_exec_oit(env, lfsck, target); } @@ -358,8 +387,12 @@ checkpoint: else if (likely(rc == 0)) lfsck->li_current_oit_processed = 0; - if (unlikely(!thread_is_running(thread))) + if (unlikely(!thread_is_running(thread))) { + CDEBUG(D_LFSCK, "%s: OIT scan exit for engine stop, " + "cookie "LPU64"\n", lfsck_lfsck2name(lfsck), + iops->store(env, di)); RETURN(0); + } } while (rc == 0 || lfsck->li_di_dir != NULL); RETURN(rc); @@ -381,8 +414,8 @@ int lfsck_master_engine(void *args) oit_di = oit_iops->init(env, oit_obj, lfsck->li_args_oit, BYPASS_CAPA); if (IS_ERR(oit_di)) { rc = PTR_ERR(oit_di); - CERROR("%s: LFSCK, fail to init iteration: rc = %d\n", - lfsck_lfsck2name(lfsck), rc); + CDEBUG(D_LFSCK, "%s: master engine fail to init iteration: " + "rc = %d\n", lfsck_lfsck2name(lfsck), rc); GOTO(fini_args, rc); } @@ -395,7 +428,7 @@ int lfsck_master_engine(void *args) GOTO(fini_oit, rc); CDEBUG(D_LFSCK, "LFSCK entry: oit_flags = %#x, dir_flags = %#x, " - "oit_cookie = "LPU64", dir_cookie = "LPU64", parent = "DFID + "oit_cookie = "LPU64", dir_cookie = "LPX64", parent = "DFID ", pid = %d\n", lfsck->li_args_oit, lfsck->li_args_dir, lfsck->li_pos_current.lp_oit_cookie, lfsck->li_pos_current.lp_dir_cookie, @@ -421,7 +454,7 @@ int lfsck_master_engine(void *args) rc = 1; CDEBUG(D_LFSCK, "LFSCK exit: oit_flags = %#x, dir_flags = %#x, " - "oit_cookie = "LPU64", dir_cookie = "LPU64", parent = "DFID + "oit_cookie = "LPU64", dir_cookie = "LPX64", parent = "DFID ", pid = %d, rc = %d\n", lfsck->li_args_oit, lfsck->li_args_dir, lfsck->li_pos_current.lp_oit_cookie, lfsck->li_pos_current.lp_dir_cookie, diff --git a/lustre/lfsck/lfsck_layout.c b/lustre/lfsck/lfsck_layout.c index 1ccc63b..2345dc5 100644 --- a/lustre/lfsck/lfsck_layout.c +++ b/lustre/lfsck/lfsck_layout.c @@ -566,6 +566,9 @@ static int lfsck_rbtree_setup(const struct lu_env *env, llsd->llsd_rbtree_valid = 1; dev->dd_record_fid_accessed = 1; + CDEBUG(D_LFSCK, "%s: layout LFSCK init OST-objects accessing bitmap\n", + lfsck_lfsck2name(lfsck)); + return 0; } @@ -596,6 +599,9 @@ static void lfsck_rbtree_cleanup(const struct lu_env *env, lu_object_put(env, &llsd->llsd_rb_obj->do_lu); llsd->llsd_rb_obj = NULL; } + + CDEBUG(D_LFSCK, "%s: layout LFSCK fini OST-objects accessing bitmap\n", + lfsck_lfsck2name(lfsck)); } static void lfsck_rbtree_update_bitmap(const struct lu_env *env, @@ -610,9 +616,6 @@ static void lfsck_rbtree_update_bitmap(const struct lu_env *env, int rc = 0; ENTRY; - CDEBUG(D_LFSCK, "%s: update bitmap for "DFID"\n", - lfsck_lfsck2name(com->lc_lfsck), PFID(fid)); - if (unlikely(!fid_is_sane(fid) || fid_is_last_id(fid))) RETURN_EXIT; @@ -664,10 +667,12 @@ out: if (rc != 0 && accessed) { struct lfsck_layout *lo = com->lc_file_ram; - CERROR("%s: Fail to update object accessed bitmap, will cause " - "incorrect LFSCK OST-object handling, so disable it to " - "cancel orphan handling for related device. rc = %d.\n", + CDEBUG(D_LFSCK, "%s: fail to update OST-objects accessing " + "bitmap, and will cause incorrect LFSCK OST-object " + "handling, so disable it to cancel orphan handling " + "for related device. rc = %d\n", lfsck_lfsck2name(com->lc_lfsck), rc); + lo->ll_flags |= LF_INCOMPLETE; lfsck_rbtree_cleanup(env, com); } @@ -751,20 +756,20 @@ static int lfsck_layout_load(const struct lu_env *env, if (rc == 0) { return -ENOENT; } else if (rc < 0) { - CWARN("%s: failed to load lfsck_layout: rc = %d\n", - lfsck_lfsck2name(com->lc_lfsck), rc); + CDEBUG(D_LFSCK, "%s: failed to load lfsck_layout: rc = %d\n", + lfsck_lfsck2name(com->lc_lfsck), rc); return rc; } else if (rc != size) { - CWARN("%s: crashed lfsck_layout, to be reset: rc = %d\n", - lfsck_lfsck2name(com->lc_lfsck), rc); + CDEBUG(D_LFSCK, "%s: lfsck_layout size %u != %u; reset it\n", + lfsck_lfsck2name(com->lc_lfsck), rc, (unsigned int)size); return 1; } lfsck_layout_le_to_cpu(lo, com->lc_file_disk); if (lo->ll_magic != LFSCK_LAYOUT_MAGIC) { - CWARN("%s: invalid lfsck_layout magic %#x != %#x, " - "to be reset\n", lfsck_lfsck2name(com->lc_lfsck), - lo->ll_magic, LFSCK_LAYOUT_MAGIC); + CDEBUG(D_LFSCK, "%s: invalid lfsck_layout magic %#x != %#x, " + "to be reset\n", lfsck_lfsck2name(com->lc_lfsck), + lo->ll_magic, LFSCK_LAYOUT_MAGIC); return 1; } @@ -785,39 +790,30 @@ static int lfsck_layout_store(const struct lu_env *env, lfsck_layout_cpu_to_le(lo, com->lc_file_ram); handle = dt_trans_create(env, lfsck->li_bottom); - if (IS_ERR(handle)) { - rc = PTR_ERR(handle); - CERROR("%s: fail to create trans for storing lfsck_layout: " - "rc = %d\n", lfsck_lfsck2name(lfsck), rc); - RETURN(rc); - } + if (IS_ERR(handle)) + GOTO(log, rc = PTR_ERR(handle)); rc = dt_declare_record_write(env, obj, lfsck_buf_get(env, lo, size), pos, handle); - if (rc != 0) { - CERROR("%s: fail to declare trans for storing lfsck_layout(1): " - "rc = %d\n", lfsck_lfsck2name(lfsck), rc); + if (rc != 0) GOTO(out, rc); - } rc = dt_trans_start_local(env, lfsck->li_bottom, handle); - if (rc != 0) { - CERROR("%s: fail to start trans for storing lfsck_layout: " - "rc = %d\n", lfsck_lfsck2name(lfsck), rc); + if (rc != 0) GOTO(out, rc); - } rc = dt_record_write(env, obj, lfsck_buf_get(env, lo, size), &pos, handle); - if (rc != 0) - CERROR("%s: fail to store lfsck_layout(1): size = %d, " - "rc = %d\n", lfsck_lfsck2name(lfsck), (int)size, rc); GOTO(out, rc); out: dt_trans_stop(env, lfsck->li_bottom, handle); +log: + if (rc != 0) + CDEBUG(D_LFSCK, "%s: fail to store lfsck_layout: rc = %d\n", + lfsck_lfsck2name(lfsck), rc); return rc; } @@ -916,9 +912,6 @@ lfsck_layout_lastid_create(const struct lu_env *env, int rc; ENTRY; - CDEBUG(D_LFSCK, "To create LAST_ID for "LPX64"\n", - fid_seq(lfsck_dto2fid(obj))); - if (bk->lb_param & LPF_DRYRUN) return 0; @@ -929,7 +922,7 @@ lfsck_layout_lastid_create(const struct lu_env *env, th = dt_trans_create(env, dt); if (IS_ERR(th)) - RETURN(rc = PTR_ERR(th)); + GOTO(log, rc = PTR_ERR(th)); rc = dt_declare_create(env, obj, la, NULL, dof, th); if (rc != 0) @@ -961,6 +954,11 @@ lfsck_layout_lastid_create(const struct lu_env *env, stop: dt_trans_stop(env, dt, th); +log: + CDEBUG(D_LFSCK, "%s: layout LFSCK will create LAST_ID for " + LPX64": rc = %d\n", + lfsck_lfsck2name(lfsck), fid_seq(lfsck_dto2fid(obj)), rc); + return rc; } @@ -1041,8 +1039,9 @@ lfsck_layout_lastid_store(const struct lu_env *env, } #endif - CDEBUG(D_LFSCK, "To sync the LAST_ID for "LPX64 - " as "LPU64"\n", lls->lls_seq, lls->lls_lastid); + CDEBUG(D_LFSCK, "%s: layout LFSCK will sync the LAST_ID for " + " "LPX64" as "LPU64"\n", + lfsck_lfsck2name(lfsck), lls->lls_seq, lls->lls_lastid); if (bk->lb_param & LPF_DRYRUN) { lls->lls_dirty = 0; @@ -1052,7 +1051,8 @@ lfsck_layout_lastid_store(const struct lu_env *env, th = dt_trans_create(env, dt); if (IS_ERR(th)) { rc1 = PTR_ERR(th); - CERROR("%s: (1) failed to store "LPX64": rc = %d\n", + CDEBUG(D_LFSCK, "%s: layout LFSCK failed to store " + "the LAST_ID for "LPX64"(1): rc = %d\n", lfsck_lfsck2name(com->lc_lfsck), lls->lls_seq, rc1); continue; @@ -1082,7 +1082,8 @@ stop: dt_trans_stop(env, dt, th); if (rc != 0) { rc1 = rc; - CERROR("%s: (2) failed to store "LPX64": rc = %d\n", + CDEBUG(D_LFSCK, "%s: layout LFSCK failed to store " + "the LAST_ID for "LPX64"(2): rc = %d\n", lfsck_lfsck2name(com->lc_lfsck), lls->lls_seq, rc1); } @@ -1170,10 +1171,16 @@ static void lfsck_layout_record_failure(const struct lu_env *env, struct lfsck_layout *lo) { lo->ll_objs_failed_phase1++; - if (unlikely(lo->ll_pos_first_inconsistent == 0)) + if (unlikely(lo->ll_pos_first_inconsistent == 0)) { lo->ll_pos_first_inconsistent = lfsck->li_obj_oit->do_index_ops->dio_it.store(env, lfsck->li_di_oit); + + CDEBUG(D_LFSCK, "%s: layout LFSCK hit first non-repaired " + "inconsistency at the pos ["LPU64"]\n", + lfsck_lfsck2name(lfsck), + lo->ll_pos_first_inconsistent); + } } static int lfsck_layout_master_async_interpret(const struct lu_env *env, @@ -1192,8 +1199,9 @@ static int lfsck_layout_master_async_interpret(const struct lu_env *env, if (rc != 0) { struct lfsck_layout *lo = com->lc_file_ram; - CERROR("%s: fail to notify %s %x for layout start: " - "rc = %d\n", lfsck_lfsck2name(com->lc_lfsck), + CDEBUG(D_LFSCK, "%s: fail to notify %s %x for layout " + "start: rc = %d\n", + lfsck_lfsck2name(com->lc_lfsck), (lr->lr_flags & LEF_TO_OST) ? "OST" : "MDT", ltd->ltd_index, rc); lo->ll_flags |= LF_INCOMPLETE; @@ -1228,11 +1236,11 @@ static int lfsck_layout_master_async_interpret(const struct lu_env *env, case LE_PHASE2_DONE: case LE_PEER_EXIT: if (rc != 0 && rc != -EALREADY) - CWARN("%s: fail to notify %s %x for layout: " - "event = %d, rc = %d\n", - lfsck_lfsck2name(com->lc_lfsck), - (lr->lr_flags & LEF_TO_OST) ? "OST" : "MDT", - ltd->ltd_index, lr->lr_event, rc); + CDEBUG(D_LFSCK, "%s: fail to notify %s %x for layout: " + "event = %d, rc = %d\n", + lfsck_lfsck2name(com->lc_lfsck), + (lr->lr_flags & LEF_TO_OST) ? "OST" : "MDT", + ltd->ltd_index, lr->lr_event, rc); break; case LE_QUERY: { struct lfsck_reply *reply; @@ -1249,7 +1257,7 @@ static int lfsck_layout_master_async_interpret(const struct lu_env *env, &RMF_LFSCK_REPLY); if (reply == NULL) { rc = -EPROTO; - CERROR("%s: invalid return value: rc = %d\n", + CDEBUG(D_LFSCK, "%s: invalid query reply: rc = %d\n", lfsck_lfsck2name(com->lc_lfsck), rc); spin_lock(<ds->ltd_lock); list_del_init(<d->ltd_layout_phase_list); @@ -1287,7 +1295,7 @@ static int lfsck_layout_master_async_interpret(const struct lu_env *env, break; } default: - CERROR("%s: unexpected event: rc = %d\n", + CDEBUG(D_LFSCK, "%s: layout LFSCK unexpected event: rc = %d\n", lfsck_lfsck2name(com->lc_lfsck), lr->lr_event); break; } @@ -1360,8 +1368,8 @@ again: lfsck_layout_master_async_interpret, laia, LFSCK_QUERY); if (rc != 0) { - CERROR("%s: fail to query %s %x for layout: rc = %d\n", - lfsck_lfsck2name(lfsck), + CDEBUG(D_LFSCK, "%s: layout LFSCK fail to query %s %x: " + "rc = %d\n", lfsck_lfsck2name(lfsck), (lr->lr_flags & LEF_TO_OST) ? "OST" : "MDT", ltd->ltd_index, rc); lfsck_tgt_put(ltd); @@ -1438,8 +1446,8 @@ static int lfsck_layout_master_notify_others(const struct lu_env *env, lfsck_layout_master_async_interpret, laia, LFSCK_NOTIFY); if (rc != 0) { - CERROR("%s: fail to notify %s %x for layout " - "start: rc = %d\n", + CDEBUG(D_LFSCK, "%s: layout LFSCK fail to " + "notify %s %x for start: rc = %d\n", lfsck_lfsck2name(lfsck), (lr->lr_flags & LEF_TO_OST) ? "OST" : "MDT", idx, rc); @@ -1521,8 +1529,9 @@ again: lfsck_layout_master_async_interpret, laia, LFSCK_NOTIFY); if (rc != 0) { - CERROR("%s: fail to notify %s %x for layout " - "stop/phase2: rc = %d\n", + CDEBUG(D_LFSCK, "%s: layout LFSCK fail to " + "notify %s %x for stop/phase2_done/" + "peer_exit: rc = %d\n", lfsck_lfsck2name(lfsck), (lr->lr_flags & LEF_TO_OST) ? "OST" : "MDT", ltd->ltd_index, rc); @@ -1569,9 +1578,9 @@ again: lfsck_layout_master_async_interpret, laia, LFSCK_NOTIFY); if (rc != 0) { - CERROR("%s: fail to notify MDT %x for layout " - "phase1 done: rc = %d\n", - lfsck_lfsck2name(lfsck), + CDEBUG(D_LFSCK, "%s: layout LFSCK fail to " + "notify MDT %x for phase1_done: " + "rc = %d\n", lfsck_lfsck2name(lfsck), ltd->ltd_index, rc); lfsck_tgt_put(ltd); } @@ -1580,7 +1589,7 @@ again: spin_unlock(<ds->ltd_lock); break; default: - CERROR("%s: unexpected LFSCK event: rc = %d\n", + CDEBUG(D_LFSCK, "%s: layout LFSCK unexpected event: rc = %d\n", lfsck_lfsck2name(lfsck), lr->lr_event); rc = -EINVAL; break; @@ -1792,6 +1801,7 @@ static int lfsck_layout_extend_lovea(const struct lu_env *env, struct lov_ost_data_v1 *objs; int rc; __u16 count; + bool hole = false; ENTRY; if (fl == LU_XATTR_CREATE || reset) { @@ -1800,8 +1810,10 @@ static int lfsck_layout_extend_lovea(const struct lu_env *env, count = ea_off + 1; LASSERT(buf->lb_len == lov_mds_md_size(count, LOV_MAGIC_V1)); - if (ea_off != 0 || reset) + if (ea_off != 0 || reset) { pattern |= LOV_PATTERN_F_HOLE; + hole = true; + } memset(lmm, 0, buf->lb_len); lmm->lmm_magic = cpu_to_le32(LOV_MAGIC_V1); @@ -1834,6 +1846,7 @@ static int lfsck_layout_extend_lovea(const struct lu_env *env, if (gap > 0) { memset(objs, 0, gap * sizeof(*objs)); lmm->lmm_pattern |= cpu_to_le32(LOV_PATTERN_F_HOLE); + hole = true; } lmm->lmm_layout_gen = @@ -1845,6 +1858,13 @@ static int lfsck_layout_extend_lovea(const struct lu_env *env, rc = lfsck_layout_refill_lovea(env, handle, parent, cfid, buf, objs, fl, ost_idx); + CDEBUG(D_LFSCK, "%s: layout LFSCK assistant extend layout EA for " + DFID": parent "DFID", OST-index %u, stripe-index %u, fl %d, " + "reset %s, %s LOV EA hole: rc = %d\n", + lfsck_lfsck2name(lfsck), PFID(cfid), PFID(lfsck_dto2fid(parent)), + ost_idx, ea_off, fl, reset ? "yes" : "no", + hole ? "with" : "without", rc); + RETURN(rc); } @@ -1906,7 +1926,7 @@ out: } /** - * This function will create the MDT-object will the given (partial) LOV EA. + * This function will create the MDT-object with the given (partial) LOV EA. * * Under some data corruption cases, the MDT-object of the file may be lost, * but its OST-objects, or some of them are there. The layout LFSCK needs to @@ -1947,7 +1967,7 @@ out: * \param[in] ea_off the stripe offset in the LOV EA * * \retval positive on repaired something - * \retval if needs to repair nothing + * \retval 0 if needs to repair nothing * \retval negative error number on failure */ static int lfsck_layout_recreate_parent(const struct lu_env *env, @@ -1982,7 +2002,7 @@ static int lfsck_layout_recreate_parent(const struct lu_env *env, if (unlikely(lfsck->li_lpf_obj == NULL)) { rc = lfsck_create_lpf(env, lfsck); if (rc != 0) - RETURN(rc); + GOTO(log, rc); } if (fid_is_zero(pfid)) { @@ -2001,13 +2021,9 @@ static int lfsck_layout_recreate_parent(const struct lu_env *env, pbuf = lfsck_buf_get(env, ff, sizeof(struct filter_fid)); cobj = lfsck_object_find_by_dev(env, ltd->ltd_tgt, cfid); if (IS_ERR(cobj)) - RETURN(PTR_ERR(cobj)); + GOTO(log, rc = PTR_ERR(cobj)); } - CDEBUG(D_LFSCK, "Re-create the lost MDT-object: parent "DFID", child " - DFID", OST-index %u, stripe-index %u, infix %s, type %s\n", - PFID(pfid), PFID(cfid), ltd->ltd_index, ea_off, infix, type); - pobj = lfsck_object_find_by_dev(env, lfsck->li_bottom, pfid); if (IS_ERR(pobj)) GOTO(put, rc = PTR_ERR(pobj)); @@ -2130,6 +2146,15 @@ put: lu_object_put(env, &pobj->do_lu); ea_buf->lb_len = buflen; +log: + if (rc < 0) + CDEBUG(D_LFSCK, "%s layout LFSCK assistant failed to " + "recreate the lost MDT-object: parent "DFID + ", child "DFID", OST-index %u, stripe-index %u, " + "infix %s, type %s: rc = %d\n", + lfsck_lfsck2name(lfsck), PFID(pfid), PFID(cfid), + ltd->ltd_index, ea_off, infix, type, rc); + return rc >= 0 ? 1 : rc; } @@ -2269,10 +2294,11 @@ static int lfsck_layout_slave_conditional_destroy(const struct lu_env *env, rc = dt_destroy(env, obj, th); if (rc == 0) - CDEBUG(D_LFSCK, "Destroy the empty OST-object "DFID" which " - "was created for reparing dangling referenced case. " - "But the original missed OST-object is found now.\n", - PFID(fid)); + CDEBUG(D_LFSCK, "%s: layout LFSCK destroyed the empty " + "OST-object "DFID" that was created for reparing " + "dangling referenced case. But the original missed " + "OST-object is found now.\n", + lfsck_lfsck2name(lfsck), PFID(fid)); GOTO(stop, rc); @@ -2327,12 +2353,6 @@ static int lfsck_layout_conflict_create(const struct lu_env *env, ostid_le_to_cpu(&slot->l_ost_oi, oi); ostid_to_fid(cfid2, oi, ost_idx2); - CDEBUG(D_LFSCK, "Handle layout EA conflict: parent "DFID - ", cur-child "DFID" on the OST %u, orphan-child " - DFID" on the OST %u, stripe-index %u\n", - PFID(lfsck_dto2fid(parent)), PFID(cfid2), ost_idx2, - PFID(cfid), ltd->ltd_index, ea_off); - /* Hold layout lock on the parent to prevent others to access. */ rc = lfsck_layout_lock(env, com, parent, &lh, MDS_INODELOCK_LAYOUT | MDS_INODELOCK_XATTR); @@ -2392,6 +2412,13 @@ unlock: out: ea_buf->lb_len = ori_len; + CDEBUG(D_LFSCK, "%s: layout LFSCK assistant replaced the conflict " + "OST-object "DFID" on the OST %x with the orphan "DFID" on " + "the OST %x: parent "DFID", stripe-index %u: rc = %d\n", + lfsck_lfsck2name(com->lc_lfsck), PFID(cfid2), ost_idx2, + PFID(cfid), ltd->ltd_index, PFID(lfsck_dto2fid(parent)), + ea_off, rc); + return rc >= 0 ? 1 : rc; } @@ -2429,14 +2456,17 @@ static int lfsck_layout_recreate_lovea(const struct lu_env *env, bool locked = false; ENTRY; - CDEBUG(D_LFSCK, "Re-create the crashed layout EA: parent " - DFID", child "DFID", OST-index %u, stripe-index %u\n", - PFID(lfsck_dto2fid(parent)), PFID(cfid), ost_idx, ea_off); - rc = lfsck_layout_lock(env, com, parent, &lh, MDS_INODELOCK_LAYOUT | MDS_INODELOCK_XATTR); - if (rc != 0) + if (rc != 0) { + CDEBUG(D_LFSCK, "%s: layout LFSCK assistant failed to recreate " + "LOV EA for "DFID": parent "DFID", OST-index %u, " + "stripe-index %u: rc = %d\n", + lfsck_lfsck2name(lfsck), PFID(cfid), + PFID(lfsck_dto2fid(parent)), ost_idx, ea_off, rc); + RETURN(rc); + } again: if (locked) { @@ -2584,6 +2614,13 @@ again: rc = lfsck_layout_refill_lovea(env, handle, parent, cfid, buf, objs, fl, ost_idx); + + CDEBUG(D_LFSCK, "%s layout LFSCK assistant fill " + "dummy layout slot for "DFID": parent "DFID + ", OST-index %u, stripe-index %u: rc = %d\n", + lfsck_lfsck2name(lfsck), PFID(cfid), + PFID(lfsck_dto2fid(parent)), ost_idx, i, rc); + GOTO(unlock_parent, rc); } @@ -2609,6 +2646,14 @@ again: rc = lfsck_layout_update_pfid(env, com, parent, cfid, ltd->ltd_tgt, i); + CDEBUG(D_LFSCK, "%s layout LFSCK assistant " + "updated OST-object's pfid for "DFID + ": parent "DFID", OST-index %u, " + "stripe-index %u: rc = %d\n", + lfsck_lfsck2name(lfsck), PFID(cfid), + PFID(lfsck_dto2fid(parent)), + ltd->ltd_index, i, rc); + RETURN(rc); } } @@ -2733,7 +2778,8 @@ static int lfsck_layout_scan_orphan(const struct lu_env *env, int rc = 0; ENTRY; - CDEBUG(D_LFSCK, "%s: start the orphan scanning for OST%04x\n", + CDEBUG(D_LFSCK, "%s: layout LFSCK assistant starts the orphan " + "scanning for OST%04x\n", lfsck_lfsck2name(lfsck), ltd->ltd_index); ostid_set_seq(oi, FID_SEQ_IDIF); @@ -2741,7 +2787,7 @@ static int lfsck_layout_scan_orphan(const struct lu_env *env, ostid_to_fid(fid, oi, ltd->ltd_index); obj = lfsck_object_find_by_dev(env, ltd->ltd_tgt, fid); if (unlikely(IS_ERR(obj))) - RETURN(PTR_ERR(obj)); + GOTO(log, rc = PTR_ERR(obj)); rc = obj->do_ops->do_index_try(env, obj, &dt_lfsck_orphan_features); if (rc != 0) @@ -2810,7 +2856,9 @@ fini: put: lu_object_put(env, &obj->do_lu); - CDEBUG(D_LFSCK, "%s: finish the orphan scanning for OST%04x, rc = %d\n", +log: + CDEBUG(D_LFSCK, "%s: layout LFSCK assistant finished the orphan " + "scanning for OST%04x: rc = %d\n", lfsck_lfsck2name(lfsck), ltd->ltd_index, rc); return rc > 0 ? 0 : rc; @@ -2850,15 +2898,8 @@ static int lfsck_layout_repair_dangling(const struct lu_env *env, else create = false; - CDEBUG(D_LFSCK, "Found dangling reference for: parent "DFID - ", child "DFID", OST-index %u, stripe-index %u, owner %u:%u. %s", - PFID(lfsck_dto2fid(parent)), PFID(lfsck_dto2fid(child)), - llr->llr_ost_idx, llr->llr_lov_idx, pla->la_uid, pla->la_gid, - create ? "Create the lost OST-object as required.\n" : - "Keep the MDT-object there by default.\n"); - if (!create) - RETURN(1); + GOTO(log, rc = 1); memset(cla, 0, sizeof(*cla)); cla->la_uid = pla->la_uid; @@ -2870,7 +2911,7 @@ static int lfsck_layout_repair_dangling(const struct lu_env *env, rc = lfsck_layout_lock(env, com, parent, &lh, MDS_INODELOCK_LAYOUT | MDS_INODELOCK_XATTR); if (rc != 0) - RETURN(rc); + GOTO(log, rc); handle = dt_trans_create(env, dev); if (IS_ERR(handle)) @@ -2921,6 +2962,16 @@ stop: unlock1: lfsck_layout_unlock(&lh); +log: + CDEBUG(D_LFSCK, "%s: layout LFSCK assistant found dangling " + "reference for: parent "DFID", child "DFID", OST-index %u, " + "stripe-index %u, owner %u/%u. %s: rc = %d\n", + lfsck_lfsck2name(com->lc_lfsck), PFID(lfsck_dto2fid(parent)), + PFID(lfsck_dto2fid(child)), llr->llr_ost_idx, + llr->llr_lov_idx, pla->la_uid, pla->la_gid, + create ? "Create the lost OST-object as required" : + "Keep the MDT-object there by default", rc); + return rc; } @@ -2945,15 +2996,10 @@ static int lfsck_layout_repair_unmatched_pair(const struct lu_env *env, int rc; ENTRY; - CDEBUG(D_LFSCK, "Repair unmatched MDT-OST pair for: parent "DFID - ", child "DFID", OST-index %u, stripe-index %u, owner %u:%u\n", - PFID(lfsck_dto2fid(parent)), PFID(lfsck_dto2fid(child)), - llr->llr_ost_idx, llr->llr_lov_idx, pla->la_uid, pla->la_gid); - rc = lfsck_layout_lock(env, com, parent, &lh, MDS_INODELOCK_LAYOUT | MDS_INODELOCK_XATTR); if (rc != 0) - RETURN(rc); + GOTO(log, rc); handle = dt_trans_create(env, dev); if (IS_ERR(handle)) @@ -3010,6 +3056,14 @@ stop: unlock1: lfsck_layout_unlock(&lh); +log: + CDEBUG(D_LFSCK, "%s: layout LFSCK assistant repaired unmatched " + "MDT-OST pair for: parent "DFID", child "DFID", OST-index %u, " + "stripe-index %u, owner %u/%u: rc = %d\n", + lfsck_lfsck2name(com->lc_lfsck), PFID(lfsck_dto2fid(parent)), + PFID(lfsck_dto2fid(child)), llr->llr_ost_idx, llr->llr_lov_idx, + pla->la_uid, pla->la_gid, rc); + return rc; } @@ -3040,15 +3094,10 @@ static int lfsck_layout_repair_multiple_references(const struct lu_env *env, int rc; ENTRY; - CDEBUG(D_LFSCK, "Repair multiple references for: parent "DFID - ", OST-index %u, stripe-index %u, owner %u:%u\n", - PFID(lfsck_dto2fid(parent)), llr->llr_ost_idx, - llr->llr_lov_idx, la->la_uid, la->la_gid); - rc = lfsck_layout_lock(env, com, parent, &lh, MDS_INODELOCK_LAYOUT | MDS_INODELOCK_XATTR); if (rc != 0) - RETURN(rc); + GOTO(log, rc); handle = dt_trans_create(env, pdev); if (IS_ERR(handle)) @@ -3132,6 +3181,13 @@ stop: unlock1: lfsck_layout_unlock(&lh); +log: + CDEBUG(D_LFSCK, "%s: layout LFSCK assistant repaired multiple " + "references for: parent "DFID", OST-index %u, stripe-index %u, " + "owner %u/%u: rc = %d\n", + lfsck_lfsck2name(com->lc_lfsck), PFID(lfsck_dto2fid(parent)), + llr->llr_ost_idx, llr->llr_lov_idx, la->la_uid, la->la_gid, rc); + return rc; } @@ -3153,14 +3209,9 @@ static int lfsck_layout_repair_owner(const struct lu_env *env, int rc; ENTRY; - CDEBUG(D_LFSCK, "Repair inconsistent file owner for: parent "DFID - ", child "DFID", OST-index %u, stripe-index %u, owner %u:%u\n", - PFID(lfsck_dto2fid(parent)), PFID(lfsck_dto2fid(child)), - llr->llr_ost_idx, llr->llr_lov_idx, pla->la_uid, pla->la_gid); - handle = dt_trans_create(env, dev); if (IS_ERR(handle)) - RETURN(PTR_ERR(handle)); + GOTO(log, rc = PTR_ERR(handle)); tla->la_uid = pla->la_uid; tla->la_gid = pla->la_gid; @@ -3180,14 +3231,8 @@ static int lfsck_layout_repair_owner(const struct lu_env *env, /* Get the latest parent's owner. */ rc = dt_attr_get(env, parent, tla, BYPASS_CAPA); - if (rc != 0) { - CWARN("%s: fail to get the latest parent's ("DFID") owner, " - "not sure whether some others chown/chgrp during the " - "LFSCK: rc = %d\n", lfsck_lfsck2name(com->lc_lfsck), - PFID(lfsck_dto2fid(parent)), rc); - + if (rc != 0) GOTO(unlock, rc); - } /* Some others chown/chgrp during the LFSCK, needs to do nothing. */ if (unlikely(tla->la_uid != pla->la_uid || @@ -3205,6 +3250,14 @@ unlock: stop: rc = lfsck_layout_trans_stop(env, dev, handle, rc); +log: + CDEBUG(D_LFSCK, "%s: layout LFSCK assistant repaired inconsistent " + "file owner for: parent "DFID", child "DFID", OST-index %u, " + "stripe-index %u, owner %u/%u: rc = %d\n", + lfsck_lfsck2name(com->lc_lfsck), PFID(lfsck_dto2fid(parent)), + PFID(lfsck_dto2fid(child)), llr->llr_ost_idx, llr->llr_lov_idx, + pla->la_uid, pla->la_gid, rc); + return rc; } @@ -3429,7 +3482,8 @@ out: rc == -EHOSTUNREACH) { /* If cannot touch the target server, * mark the LFSCK as INCOMPLETE. */ - CERROR("%s: Fail to talk with OST %x: rc = %d.\n", + CDEBUG(D_LFSCK, "%s: layout LFSCK assistant fail to " + "talk with OST %x: rc = %d\n", lfsck_lfsck2name(lfsck), llr->llr_ost_idx, rc); lo->ll_flags |= LF_INCOMPLETE; lo->ll_objs_skipped++; @@ -3486,7 +3540,8 @@ static int lfsck_layout_assistant(void *args) rc = lfsck_layout_master_notify_others(env, com, lr); if (rc != 0) { - CERROR("%s: fail to notify others for layout start: rc = %d\n", + CDEBUG(D_LFSCK, "%s: layout LFSCK assistant failed to notify " + "others for LFSCK start: rc = %d\n", lfsck_lfsck2name(lfsck), rc); GOTO(fini, rc); } @@ -3555,8 +3610,9 @@ static int lfsck_layout_assistant(void *args) lr->lr_status = llmd->llmd_post_result; rc = lfsck_layout_master_notify_others(env, com, lr); if (rc != 0) - CERROR("%s: failed to notify others " - "for layout post: rc = %d\n", + CDEBUG(D_LFSCK, "%s: layout LFSCK assistant " + "failed to notify others for LFSCK " + "post: rc = %d\n", lfsck_lfsck2name(lfsck), rc); /* Wakeup the master engine to go ahead. */ @@ -3569,6 +3625,9 @@ static int lfsck_layout_assistant(void *args) llmd->llmd_in_double_scan = 1; wake_up_all(&mthread->t_ctl_waitq); + CDEBUG(D_LFSCK, "%s: layout LFSCK assistant phase2 " + "scan start\n", lfsck_lfsck2name(lfsck)); + com->lc_new_checked = 0; com->lc_new_scanned = 0; com->lc_time_last_checkpoint = cfs_time_current(); @@ -3690,7 +3749,7 @@ cleanup2: lr->lr_status = LS_CO_STOPPED; break; default: - CERROR("%s: unknown status: rc = %d\n", + CDEBUG(D_LFSCK, "%s: unknown status: rc = %d\n", lfsck_lfsck2name(lfsck), lfsck->li_status); lr->lr_status = LS_CO_FAILED; @@ -3709,7 +3768,8 @@ cleanup2: rc1 = lfsck_layout_master_notify_others(env, com, lr); if (rc1 != 0) { - CERROR("%s: failed to notify others for layout quit: rc = %d\n", + CDEBUG(D_LFSCK, "%s: layout LFSCK assistant failed to " + "notify others for LFSCK quit: rc = %d\n", lfsck_lfsck2name(lfsck), rc1); rc = rc1; } @@ -3717,8 +3777,16 @@ cleanup2: /* Under force exit case, some requests may be just freed without * verification, those objects should be re-handled when next run. * So not update the on-disk tracing file under such case. */ - if (llmd->llmd_in_double_scan && !llmd->llmd_exit) - rc1 = lfsck_layout_double_scan_result(env, com, rc); + if (llmd->llmd_in_double_scan) { + struct lfsck_layout *lo = com->lc_file_ram; + + if (!llmd->llmd_exit) + rc1 = lfsck_layout_double_scan_result(env, com, rc); + + CDEBUG(D_LFSCK, "%s: layout LFSCK assistant phase2 scan " + "finished, status %d: rc = %d\n", + lfsck_lfsck2name(lfsck), lo->ll_status, rc1); + } fini: if (llmd->llmd_in_double_scan) @@ -3744,6 +3812,7 @@ lfsck_layout_slave_async_interpret(const struct lu_env *env, struct lfsck_component *com = llsaa->llsaa_com; struct lfsck_layout_slave_target *llst = llsaa->llsaa_llst; struct lfsck_layout_slave_data *llsd = com->lc_data; + struct lfsck_reply *lr = NULL; bool done = false; if (rc != 0) { @@ -3752,15 +3821,20 @@ lfsck_layout_slave_async_interpret(const struct lu_env *env, * the target finished the LFSCK prcoessing. */ done = true; } else { - struct lfsck_reply *lr; - lr = req_capsule_server_get(&req->rq_pill, &RMF_LFSCK_REPLY); if (lr->lr_status != LS_SCANNING_PHASE1 && lr->lr_status != LS_SCANNING_PHASE2) done = true; } - if (done) + + if (done) { + CDEBUG(D_LFSCK, "%s: layout LFSCK slave gets the MDT %x " + "status %d\n", lfsck_lfsck2name(com->lc_lfsck), + llst->llst_index, lr != NULL ? lr->lr_status : rc); + lfsck_layout_llst_del(llsd, llst); + } + lfsck_layout_llst_put(llst); lfsck_component_put(env, com); class_export_put(exp); @@ -3849,7 +3923,7 @@ lfsck_layout_slave_query_master(const struct lu_env *env, set = ptlrpc_prep_set(); if (set == NULL) - RETURN(-ENOMEM); + GOTO(log, rc = -ENOMEM); memset(lr, 0, sizeof(*lr)); lr->lr_index = lfsck_dev_idx(lfsck->li_bottom); @@ -3883,9 +3957,11 @@ lfsck_layout_slave_query_master(const struct lu_env *env, rc = lfsck_layout_async_query(env, com, exp, llst, lr, set); if (rc != 0) { - CERROR("%s: slave fail to query %s for layout: " - "rc = %d\n", lfsck_lfsck2name(lfsck), + CDEBUG(D_LFSCK, "%s: layout LFSCK slave fail to " + "query %s for layout: rc = %d\n", + lfsck_lfsck2name(lfsck), exp->exp_obd->obd_name, rc); + rc1 = rc; lfsck_layout_llst_put(llst); class_export_put(exp); @@ -3897,7 +3973,13 @@ lfsck_layout_slave_query_master(const struct lu_env *env, rc = ptlrpc_set_wait(set); ptlrpc_set_destroy(set); - RETURN(rc1 != 0 ? rc1 : rc); + GOTO(log, rc = (rc1 != 0 ? rc1 : rc)); + +log: + CDEBUG(D_LFSCK, "%s: layout LFSCK slave queries master: rc = %d\n", + lfsck_lfsck2name(com->lc_lfsck), rc); + + return rc; } static void @@ -3914,6 +3996,9 @@ lfsck_layout_slave_notify_master(const struct lu_env *env, int rc; ENTRY; + CDEBUG(D_LFSCK, "%s: layout LFSCK slave notifies master\n", + lfsck_lfsck2name(com->lc_lfsck)); + set = ptlrpc_prep_set(); if (set == NULL) RETURN_EXIT; @@ -3951,9 +4036,11 @@ lfsck_layout_slave_notify_master(const struct lu_env *env, rc = lfsck_layout_async_notify(env, exp, lr, set); if (rc != 0) - CERROR("%s: slave fail to notify %s for layout: " - "rc = %d\n", lfsck_lfsck2name(lfsck), + CDEBUG(D_LFSCK, "%s: layout LFSCK slave fail to " + "notify %s for layout: rc = %d\n", + lfsck_lfsck2name(lfsck), exp->exp_obd->obd_name, rc); + lfsck_layout_llst_put(llst); class_export_put(exp); spin_lock(&llsd->llsd_lock); @@ -4135,7 +4222,7 @@ static int lfsck_layout_slave_repair_pfid(const struct lu_env *env, obj = lfsck_object_find_by_dev(env, dev, &lr->lr_fid); if (IS_ERR(obj)) - RETURN(PTR_ERR(obj)); + GOTO(log, rc = PTR_ERR(obj)); fid_cpu_to_le(&ff->ff_parent, &lr->lr_fid2); buf = lfsck_buf_get(env, ff, sizeof(*ff)); @@ -4166,6 +4253,11 @@ unlock: dt_write_unlock(env, obj); lu_object_put(env, &obj->do_lu); +log: + CDEBUG(D_LFSCK, "%s: layout LFSCK slave repaired pfid for "DFID + ", parent "DFID": rc = %d\n", lfsck_lfsck2name(com->lc_lfsck), + PFID(&lr->lr_fid), PFID(&lr->lr_fid2), rc); + return rc; } @@ -4195,6 +4287,9 @@ static int lfsck_layout_reset(const struct lu_env *env, rc = lfsck_layout_store(env, com); up_write(&com->lc_sem); + CDEBUG(D_LFSCK, "%s: layout LFSCK reset: rc = %d\n", + lfsck_lfsck2name(com->lc_lfsck), rc); + return rc; } @@ -4249,6 +4344,10 @@ static int lfsck_layout_master_checkpoint(const struct lu_env *env, rc = lfsck_layout_store(env, com); up_write(&com->lc_sem); + CDEBUG(D_LFSCK, "%s: layout LFSCK master checkpoint at the pos [" + LPU64"]: rc = %d\n", lfsck_lfsck2name(lfsck), + lfsck->li_pos_current.lp_oit_cookie, rc); + return rc; } @@ -4263,7 +4362,6 @@ static int lfsck_layout_slave_checkpoint(const struct lu_env *env, return 0; down_write(&com->lc_sem); - if (init) { lo->ll_pos_latest_start = lfsck->li_pos_current.lp_oit_cookie; } else { @@ -4277,9 +4375,12 @@ static int lfsck_layout_slave_checkpoint(const struct lu_env *env, } rc = lfsck_layout_store(env, com); - up_write(&com->lc_sem); + CDEBUG(D_LFSCK, "%s: layout LFSCK slave checkpoint at the pos [" + LPU64"]: rc = %d\n", lfsck_lfsck2name(lfsck), + lfsck->li_pos_current.lp_oit_cookie, rc); + return rc; } @@ -4303,8 +4404,12 @@ static int lfsck_layout_prep(const struct lu_env *env, if (rc == 0) rc = lfsck_set_param(env, lfsck, start, true); - if (rc != 0) + if (rc != 0) { + CDEBUG(D_LFSCK, "%s: layout LFSCK prep failed: " + "rc = %d\n", lfsck_lfsck2name(lfsck), rc); + return rc; + } } down_write(&com->lc_sem); @@ -4382,6 +4487,10 @@ static int lfsck_layout_slave_prep(const struct lu_env *env, write_unlock(&llsd->llsd_rb_lock); } + CDEBUG(D_LFSCK, "%s: layout LFSCK slave prep done, start pos [" + LPU64"]\n", lfsck_lfsck2name(lfsck), + com->lc_pos_start.lp_oit_cookie); + return rc; } @@ -4417,7 +4526,7 @@ static int lfsck_layout_master_prep(const struct lu_env *env, task = kthread_run(lfsck_layout_assistant, lta, "lfsck_layout"); if (IS_ERR(task)) { rc = PTR_ERR(task); - CERROR("%s: Cannot start LFSCK layout assistant thread: " + CERROR("%s: cannot start LFSCK layout assistant thread: " "rc = %d\n", lfsck_lfsck2name(lfsck), rc); lfsck_thread_args_fini(lta); } else { @@ -4433,6 +4542,10 @@ static int lfsck_layout_master_prep(const struct lu_env *env, rc = 0; } + CDEBUG(D_LFSCK, "%s: layout LFSCK master prep done, start pos [" + LPU64"\n", lfsck_lfsck2name(lfsck), + com->lc_pos_start.lp_oit_cookie); + RETURN(rc); } @@ -4505,8 +4618,8 @@ static int lfsck_layout_scan_stripes(const struct lu_env *env, ostid_to_fid(fid, oi, index); tgt = lfsck_tgt_get(ltds, index); if (unlikely(tgt == NULL)) { - CERROR("%s: Cannot talk with OST %x which did not join " - "the layout LFSCK.\n", + CDEBUG(D_LFSCK, "%s: cannot talk with OST %x which " + "did not join the layout LFSCK\n", lfsck_lfsck2name(lfsck), index); lo->ll_flags |= LF_INCOMPLETE; goto next; @@ -4612,6 +4725,7 @@ static int lfsck_layout_master_exec_oit(const struct lu_env *env, int rc = 0; bool locked = false; bool stripe = false; + bool bad_oi = false; ENTRY; if (!S_ISREG(lfsck_object_type(obj))) @@ -4642,8 +4756,7 @@ again: GOTO(out, stripe = true); /* Inconsistent lmm_oi, should be repaired. */ - CDEBUG(D_LFSCK, "Repair bad lmm_oi for "DFID"\n", - PFID(lfsck_dto2fid(obj))); + bad_oi = true; if (bk->lb_param & LPF_DRYRUN) { down_write(&com->lc_sem); @@ -4706,6 +4819,13 @@ out: dt_trans_stop(env, dev, handle); lfsck_layout_unlock(&lh); + + if (bad_oi) + CDEBUG(D_LFSCK, "%s: layout LFSCK master %s bad lmm_oi for " + DFID": rc = %d\n", lfsck_lfsck2name(lfsck), + bk->lb_param & LPF_DRYRUN ? "found" : "repaired", + PFID(lfsck_dto2fid(obj)), rc); + if (stripe) { rc = lfsck_layout_scan_stripes(env, com, obj, lmm); } else { @@ -4769,6 +4889,9 @@ static int lfsck_layout_slave_exec_oit(const struct lu_env *env, lls->lls_seq = seq; rc = lfsck_layout_lastid_load(env, com, lls); if (rc != 0) { + CDEBUG(D_LFSCK, "%s: layout LFSCK failed to " + "load LAST_ID for "LPX64": rc = %d\n", + lfsck_lfsck2name(com->lc_lfsck), seq, rc); lo->ll_objs_failed_phase1++; OBD_FREE_PTR(lls); GOTO(unlock, rc); @@ -4789,8 +4912,8 @@ static int lfsck_layout_slave_exec_oit(const struct lu_env *env, /* OFD may create new objects during LFSCK scanning. */ rc = lfsck_layout_lastid_reload(env, com, lls); if (unlikely(rc != 0)) - CWARN("%s: failed to reload LAST_ID for "LPX64 - ": rc = %d\n", + CDEBUG(D_LFSCK, "%s: layout LFSCK failed to " + "reload LAST_ID for "LPX64": rc = %d\n", lfsck_lfsck2name(com->lc_lfsck), lls->lls_seq, rc); if (oid <= lls->lls_lastid) @@ -4892,6 +5015,9 @@ static int lfsck_layout_master_post(const struct lu_env *env, rc = lfsck_layout_store(env, com); up_write(&com->lc_sem); + CDEBUG(D_LFSCK, "%s: layout LFSCK master post done: rc = %d\n", + lfsck_lfsck2name(lfsck), rc); + RETURN(rc); } @@ -4911,7 +5037,6 @@ static int lfsck_layout_slave_post(const struct lu_env *env, LASSERT(lfsck->li_out_notify != NULL); down_write(&com->lc_sem); - spin_lock(&lfsck->li_lock); if (!init) lo->ll_pos_last_checkpoint = @@ -4954,7 +5079,6 @@ static int lfsck_layout_slave_post(const struct lu_env *env, } rc = lfsck_layout_store(env, com); - up_write(&com->lc_sem); lfsck_layout_slave_notify_master(env, com, LE_PHASE1_DONE, result); @@ -4962,6 +5086,9 @@ static int lfsck_layout_slave_post(const struct lu_env *env, if (result <= 0) lfsck_rbtree_cleanup(env, com); + CDEBUG(D_LFSCK, "%s: layout LFSCK slave post done: rc = %d\n", + lfsck_lfsck2name(lfsck), rc); + return rc; } @@ -5184,6 +5311,9 @@ static int lfsck_layout_slave_double_scan(const struct lu_env *env, RETURN(0); } + CDEBUG(D_LFSCK, "%s: layout LFSCK slave phase2 scan start\n", + lfsck_lfsck2name(lfsck)); + atomic_inc(&lfsck->li_double_scan_count); com->lc_new_checked = 0; @@ -5230,6 +5360,10 @@ done: if (atomic_dec_and_test(&lfsck->li_double_scan_count)) wake_up_all(&lfsck->li_thread.t_ctl_waitq); + CDEBUG(D_LFSCK, "%s: layout LFSCK slave phase2 scan finished, " + "status %d: rc = %d\n", + lfsck_lfsck2name(lfsck), lo->ll_status, rc); + return rc; } @@ -5356,6 +5490,11 @@ static int lfsck_layout_master_in_notify(const struct lu_env *env, RETURN(rc); } + CDEBUG(D_LFSCK, "%s: layout LFSCK master handle notify %u " + "from %s %x, status %d\n", lfsck_lfsck2name(lfsck), + lr->lr_event, (lr->lr_flags & LEF_TO_OST) ? "OST" : "MDT", + lr->lr_index, lr->lr_status); + if (lr->lr_event != LE_PHASE1_DONE && lr->lr_event != LE_PHASE2_DONE && lr->lr_event != LE_PEER_EXIT) @@ -5379,10 +5518,6 @@ static int lfsck_layout_master_in_notify(const struct lu_env *env, if (lr->lr_status <= 0) { ltd->ltd_layout_done = 1; list_del_init(<d->ltd_layout_list); - CWARN("%s: %s %x failed/stopped at phase1: rc = %d.\n", - lfsck_lfsck2name(lfsck), - (lr->lr_flags & LEF_TO_OST) ? "OST" : "MDT", - ltd->ltd_index, lr->lr_status); lo->ll_flags |= LF_INCOMPLETE; fail = true; break; @@ -5410,13 +5545,8 @@ static int lfsck_layout_master_in_notify(const struct lu_env *env, fail = true; ltd->ltd_layout_done = 1; list_del_init(<d->ltd_layout_list); - if (!(lfsck->li_bookmark_ram.lb_param & LPF_FAILOUT)) { - CWARN("%s: the peer %s %x exit layout LFSCK.\n", - lfsck_lfsck2name(lfsck), - (lr->lr_flags & LEF_TO_OST) ? "OST" : "MDT", - ltd->ltd_index); + if (!(lfsck->li_bookmark_ram.lb_param & LPF_FAILOUT)) lo->ll_flags |= LF_INCOMPLETE; - } break; default: break; @@ -5489,6 +5619,9 @@ static int lfsck_layout_slave_in_notify(const struct lu_env *env, } case LE_PHASE2_DONE: case LE_PEER_EXIT: + CDEBUG(D_LFSCK, "%s: layout LFSCK slave handle notify %u " + "from MDT %x, status %d\n", lfsck_lfsck2name(lfsck), + lr->lr_event, lr->lr_index, lr->lr_status); break; default: RETURN(-EINVAL); @@ -5566,7 +5699,8 @@ static int lfsck_layout_master_stop_notify(const struct lu_env *env, lfsck_layout_master_async_interpret, laia, LFSCK_NOTIFY); if (rc != 0) { - CERROR("%s: Fail to notify %s %x for co-stop: rc = %d\n", + CDEBUG(D_LFSCK, "%s: layout LFSCK fail to notify %s %x " + "for co-stop: rc = %d\n", lfsck_lfsck2name(lfsck), (lr->lr_flags & LEF_TO_OST) ? "OST" : "MDT", ltd->ltd_index, rc); @@ -5747,7 +5881,7 @@ int lfsck_layout_setup(const struct lu_env *env, struct lfsck_instance *lfsck) spin_unlock(&lfsck->li_lock); break; default: - CERROR("%s: unknown lfsck_layout status: rc = %u\n", + CERROR("%s: unknown lfsck_layout status %d\n", lfsck_lfsck2name(lfsck), lo->ll_status); /* fall through */ case LS_SCANNING_PHASE1: @@ -5782,8 +5916,11 @@ out: if (root != NULL && !IS_ERR(root)) lu_object_put(env, &root->do_lu); - if (rc != 0) + if (rc != 0) { lfsck_component_cleanup(env, com); + CERROR("%s: fail to init layout LFSCK component: rc = %d\n", + lfsck_lfsck2name(lfsck), rc); + } return rc; } @@ -5871,6 +6008,9 @@ static void lfsck_layout_destroy_orphan(const struct lu_env *env, stop: dt_trans_stop(env, dev, handle); + CDEBUG(D_LFSCK, "destroy orphan OST-object "DFID": rc = %d\n", + PFID(lfsck_dto2fid(obj)), rc); + RETURN_EXIT; } @@ -5991,6 +6131,10 @@ static struct dt_it *lfsck_orphan_it_init(const struct lu_env *env, out: if (com != NULL) lfsck_component_put(env, com); + + CDEBUG(D_LFSCK, "%s: init the orphan iteration: rc = %d\n", + lfsck_lfsck2name(lfsck), rc); + lfsck_instance_put(env, lfsck); if (rc != 0) { if (it != NULL) @@ -6011,6 +6155,9 @@ static void lfsck_orphan_it_fini(const struct lu_env *env, struct lfsck_layout_slave_target *llst; if (com != NULL) { + CDEBUG(D_LFSCK, "%s: fini the orphan iteration\n", + lfsck_lfsck2name(com->lc_lfsck)); + llsd = com->lc_data; read_unlock(&llsd->llsd_rb_lock); llst = it->loi_llst; @@ -6311,10 +6458,11 @@ static int lfsck_orphan_it_load(const struct lu_env *env, LASSERT(llst != NULL); if (hash != llst->llst_hash) { - CWARN("%s: the given hash "LPU64" for orphan iteration does " - "not match the one when fini "LPU64", to be reset.\n", - lfsck_lfsck2name(it->loi_com->lc_lfsck), hash, - llst->llst_hash); + CDEBUG(D_LFSCK, "%s: the given hash "LPU64" for orphan " + "iteration does not match the one when fini " + LPU64", to be reset.\n", + lfsck_lfsck2name(it->loi_com->lc_lfsck), hash, + llst->llst_hash); fid_zero(&llst->llst_fid); llst->llst_hash = 0; } diff --git a/lustre/lfsck/lfsck_lib.c b/lustre/lfsck/lfsck_lib.c index c509cbd..03986d2 100644 --- a/lustre/lfsck/lfsck_lib.c +++ b/lustre/lfsck/lfsck_lib.c @@ -948,7 +948,7 @@ int lfsck_pos_dump(struct seq_file *m, struct lfsck_position *pos, seq_printf(m, "%s: "LPU64", N/A, N/A\n", prefix, pos->lp_oit_cookie); } else { - seq_printf(m, "%s: "LPU64", "DFID", "LPU64"\n", + seq_printf(m, "%s: "LPU64", "DFID", "LPX64"\n", prefix, pos->lp_oit_cookie, PFID(&pos->lp_dir_parent), pos->lp_dir_cookie); } @@ -1606,8 +1606,8 @@ int lfsck_async_request(const struct lu_env *env, struct obd_export *exp, format = &RQF_LFSCK_QUERY; break; default: - CERROR("%s: unknown async request: opc = %d\n", - exp->exp_obd->obd_name, request); + CDEBUG(D_LFSCK, "%s: unknown async request %d: rc = %d\n", + exp->exp_obd->obd_name, request, -EINVAL); return -EINVAL; } @@ -1806,12 +1806,8 @@ static int lfsck_stop_all(const struct lu_env *env, LASSERT(stop->ls_flags & LPF_BROADCAST); set = ptlrpc_prep_set(); - if (unlikely(set == NULL)) { - CERROR("%s: cannot allocate memory for stop LFSCK on " - "all targets\n", lfsck_lfsck2name(lfsck)); - + if (unlikely(set == NULL)) RETURN(-ENOMEM); - } memset(lr, 0, sizeof(*lr)); lr->lr_event = LE_STOP; @@ -1839,8 +1835,8 @@ static int lfsck_stop_all(const struct lu_env *env, if (rc != 0) { lfsck_interpret(env, lfsck, NULL, laia, rc); lfsck_tgt_put(ltd); - CWARN("%s: cannot notify MDT %x for LFSCK stop: " - "rc = %d\n", lfsck_lfsck2name(lfsck), idx, rc); + CERROR("%s: cannot notify MDT %x for LFSCK stop: " + "rc = %d\n", lfsck_lfsck2name(lfsck), idx, rc); rc1 = rc; } } @@ -1856,8 +1852,8 @@ static int lfsck_stop_all(const struct lu_env *env, rc = 0; if (rc != 0) - CWARN("%s: fail to stop LFSCK on some MDTs: rc = %d\n", - lfsck_lfsck2name(lfsck), rc); + CERROR("%s: fail to stop LFSCK on some MDTs: rc = %d\n", + lfsck_lfsck2name(lfsck), rc); RETURN(rc != 0 ? rc : rc1); } @@ -1880,21 +1876,8 @@ static int lfsck_start_all(const struct lu_env *env, LASSERT(start->ls_flags & LPF_BROADCAST); set = ptlrpc_prep_set(); - if (unlikely(set == NULL)) { - if (bk->lb_param & LPF_FAILOUT) { - CERROR("%s: cannot allocate memory for start LFSCK on " - "all targets, failout.\n", - lfsck_lfsck2name(lfsck)); - - RETURN(-ENOMEM); - } else { - CWARN("%s: cannot allocate memory for start LFSCK on " - "all targets, partly scan.\n", - lfsck_lfsck2name(lfsck)); - - RETURN(0); - } - } + if (unlikely(set == NULL)) + RETURN(-ENOMEM); memset(lr, 0, sizeof(*lr)); lr->lr_event = LE_START; @@ -1926,17 +1909,10 @@ static int lfsck_start_all(const struct lu_env *env, if (rc != 0) { lfsck_interpret(env, lfsck, NULL, laia, rc); lfsck_tgt_put(ltd); - if (bk->lb_param & LPF_FAILOUT) { - CERROR("%s: cannot notify MDT %x for LFSCK " - "start, failout: rc = %d\n", - lfsck_lfsck2name(lfsck), idx, rc); - break; - } else { - CWARN("%s: cannot notify MDT %x for LFSCK " - "start, partly scan: rc = %d\n", - lfsck_lfsck2name(lfsck), idx, rc); - rc = 0; - } + CERROR("%s: cannot notify MDT %x for LFSCK " + "start, failout: rc = %d\n", + lfsck_lfsck2name(lfsck), idx, rc); + break; } } up_read(<ds->ltd_rw_sem); @@ -1954,22 +1930,15 @@ static int lfsck_start_all(const struct lu_env *env, rc = laia->laia_result; if (rc != 0) { - if (bk->lb_param & LPF_FAILOUT) { - struct lfsck_stop *stop = &info->lti_stop; - - CERROR("%s: cannot start LFSCK on some MDTs, " - "stop all: rc = %d\n", - lfsck_lfsck2name(lfsck), rc); - if (rc != -EALREADY) { - stop->ls_status = LS_FAILED; - stop->ls_flags = LPF_ALL_TGT | LPF_BROADCAST; - lfsck_stop_all(env, lfsck, stop); - } - } else { - CWARN("%s: cannot start LFSCK on some MDTs, " - "partly scan: rc = %d\n", - lfsck_lfsck2name(lfsck), rc); - rc = 0; + struct lfsck_stop *stop = &info->lti_stop; + + CERROR("%s: cannot start LFSCK on some MDTs, " + "stop all: rc = %d\n", + lfsck_lfsck2name(lfsck), rc); + if (rc != -EALREADY) { + stop->ls_status = LS_FAILED; + stop->ls_flags = LPF_ALL_TGT | LPF_BROADCAST; + lfsck_stop_all(env, lfsck, stop); } } diff --git a/lustre/lfsck/lfsck_namespace.c b/lustre/lfsck/lfsck_namespace.c index 5f4ab64..0016a85 100644 --- a/lustre/lfsck/lfsck_namespace.c +++ b/lustre/lfsck/lfsck_namespace.c @@ -138,16 +138,17 @@ static int lfsck_namespace_load(const struct lu_env *env, lfsck_namespace_le_to_cpu(ns, (struct lfsck_namespace *)com->lc_file_disk); if (ns->ln_magic != LFSCK_NAMESPACE_MAGIC) { - CWARN("%s: invalid lfsck_namespace magic %#x != %#x\n", - lfsck_lfsck2name(com->lc_lfsck), ns->ln_magic, - LFSCK_NAMESPACE_MAGIC); + CDEBUG(D_LFSCK, "%s: invalid lfsck_namespace magic " + "%#x != %#x\n", lfsck_lfsck2name(com->lc_lfsck), + ns->ln_magic, LFSCK_NAMESPACE_MAGIC); rc = 1; } else { rc = 0; } } else if (rc != -ENODATA) { - CERROR("%s: fail to load lfsck_namespace: expected = %d, " - "rc = %d\n", lfsck_lfsck2name(com->lc_lfsck), len, rc); + CDEBUG(D_LFSCK, "%s: fail to load lfsck_namespace, " + "expected = %d: rc = %d\n", + lfsck_lfsck2name(com->lc_lfsck), len, rc); if (rc >= 0) rc = 1; } @@ -167,42 +168,34 @@ static int lfsck_namespace_store(const struct lu_env *env, lfsck_namespace_cpu_to_le((struct lfsck_namespace *)com->lc_file_disk, (struct lfsck_namespace *)com->lc_file_ram); handle = dt_trans_create(env, lfsck->li_bottom); - if (IS_ERR(handle)) { - rc = PTR_ERR(handle); - CERROR("%s: fail to create trans for storing lfsck_namespace: " - "rc = %d\n", lfsck_lfsck2name(lfsck), rc); - RETURN(rc); - } + if (IS_ERR(handle)) + GOTO(log, rc = PTR_ERR(handle)); rc = dt_declare_xattr_set(env, obj, lfsck_buf_get(env, com->lc_file_disk, len), XATTR_NAME_LFSCK_NAMESPACE, 0, handle); - if (rc != 0) { - CERROR("%s: fail to declare trans for storing lfsck_namespace: " - "rc = %d\n", lfsck_lfsck2name(lfsck), rc); + if (rc != 0) GOTO(out, rc); - } rc = dt_trans_start_local(env, lfsck->li_bottom, handle); - if (rc != 0) { - CERROR("%s: fail to start trans for storing lfsck_namespace: " - "rc = %d\n", lfsck_lfsck2name(lfsck), rc); + if (rc != 0) GOTO(out, rc); - } rc = dt_xattr_set(env, obj, lfsck_buf_get(env, com->lc_file_disk, len), XATTR_NAME_LFSCK_NAMESPACE, init ? LU_XATTR_CREATE : LU_XATTR_REPLACE, handle, BYPASS_CAPA); - if (rc != 0) - CERROR("%s: fail to store lfsck_namespace: len = %d, " - "rc = %d\n", lfsck_lfsck2name(lfsck), len, rc); GOTO(out, rc); out: dt_trans_stop(env, lfsck->li_bottom, handle); + +log: + if (rc != 0) + CDEBUG(D_LFSCK, "%s: fail to store lfsck_namespace: rc = %d\n", + lfsck_lfsck2name(lfsck), rc); return rc; } @@ -318,11 +311,8 @@ static int lfsck_namespace_update(const struct lu_env *env, if (exist) { rc = dt_delete(env, obj, (const struct dt_key *)key, handle, BYPASS_CAPA); - if (rc != 0) { - CERROR("%s: fail to insert "DFID": rc = %d\n", - lfsck_lfsck2name(com->lc_lfsck), PFID(fid), rc); + if (rc != 0) GOTO(out, rc); - } } rc = dt_insert(env, obj, (const struct dt_rec *)&flags, @@ -600,9 +590,11 @@ shrink: if (bk->lb_param & LPF_DRYRUN) RETURN(1); - CDEBUG(D_LFSCK, "Remove linkEA: "DFID"[%.*s], "DFID"\n", - PFID(lfsck_dto2fid(child)), cname->ln_namelen, cname->ln_name, - PFID(pfid)); + CDEBUG(D_LFSCK, "%s: namespace LFSCK remove invalid linkEA " + "for the object: "DFID", parent "DFID", name %.*s\n", + lfsck_lfsck2name(lfsck), PFID(lfsck_dto2fid(child)), + PFID(pfid), cname->ln_namelen, cname->ln_name); + linkea_del_buf(&ldata, cname); update = true; } @@ -627,10 +619,10 @@ stop: if (rc == 0 && !lfsck_is_dead_obj(child) && ldata.ld_leh != NULL && ldata.ld_leh->leh_reccount != la->la_nlink) - CWARN("%s: the object "DFID" linkEA entry count %u " - "may not match its hardlink count %u\n", - lfsck_lfsck2name(lfsck), PFID(cfid), - ldata.ld_leh->leh_reccount, la->la_nlink); + CDEBUG(D_LFSCK, "%s: the object "DFID" linkEA entry " + "count %u may not match its hardlink count %u\n", + lfsck_lfsck2name(lfsck), PFID(cfid), + ldata.ld_leh->leh_reccount, la->la_nlink); dt_write_unlock(env, child); } @@ -660,12 +652,10 @@ static int lfsck_namespace_reset(const struct lu_env *env, root = dt_locate(env, lfsck->li_bottom, &lfsck->li_local_root_fid); if (IS_ERR(root)) - RETURN(PTR_ERR(root)); + GOTO(log, rc = PTR_ERR(root)); - if (unlikely(!dt_try_as_dir(env, root))) { - lu_object_put(env, &root->do_lu); - RETURN(-ENOTDIR); - } + if (unlikely(!dt_try_as_dir(env, root))) + GOTO(put, rc = -ENOTDIR); down_write(&com->lc_sem); if (init) { @@ -706,7 +696,12 @@ static int lfsck_namespace_reset(const struct lu_env *env, out: up_write(&com->lc_sem); + +put: lu_object_put(env, &root->do_lu); +log: + CDEBUG(D_LFSCK, "%s: namespace LFSCK reset: rc = %d\n", + lfsck_lfsck2name(lfsck), rc); return rc; } @@ -720,9 +715,17 @@ lfsck_namespace_fail(const struct lu_env *env, struct lfsck_component *com, if (new_checked) com->lc_new_checked++; ns->ln_items_failed++; - if (lfsck_pos_is_zero(&ns->ln_pos_first_inconsistent)) + if (lfsck_pos_is_zero(&ns->ln_pos_first_inconsistent)) { lfsck_pos_fill(env, com->lc_lfsck, &ns->ln_pos_first_inconsistent, false); + + CDEBUG(D_LFSCK, "%s: namespace LFSCK hit first non-repaired " + "inconsistency at the pos ["LPU64", "DFID", "LPX64"]\n", + lfsck_lfsck2name(com->lc_lfsck), + ns->ln_pos_first_inconsistent.lp_oit_cookie, + PFID(&ns->ln_pos_first_inconsistent.lp_dir_parent), + ns->ln_pos_first_inconsistent.lp_dir_cookie); + } up_write(&com->lc_sem); } @@ -737,7 +740,6 @@ static int lfsck_namespace_checkpoint(const struct lu_env *env, return 0; down_write(&com->lc_sem); - if (init) { ns->ln_pos_latest_start = lfsck->li_pos_current; } else { @@ -750,8 +752,14 @@ static int lfsck_namespace_checkpoint(const struct lu_env *env, } rc = lfsck_namespace_store(env, com, false); - up_write(&com->lc_sem); + + CDEBUG(D_LFSCK, "%s: namespace LFSCK checkpoint at the pos ["LPU64 + ", "DFID", "LPX64"]: rc = %d\n", lfsck_lfsck2name(lfsck), + lfsck->li_pos_current.lp_oit_cookie, + PFID(&lfsck->li_pos_current.lp_dir_parent), + lfsck->li_pos_current.lp_dir_cookie, rc); + return rc; } @@ -770,12 +778,15 @@ static int lfsck_namespace_prep(const struct lu_env *env, if (rc == 0) rc = lfsck_set_param(env, lfsck, lsp->lsp_start, true); - if (rc != 0) + if (rc != 0) { + CDEBUG(D_LFSCK, "%s: namespace LFSCK prep failed: " + "rc = %d\n", lfsck_lfsck2name(lfsck), rc); + return rc; + } } down_write(&com->lc_sem); - ns->ln_time_latest_start = cfs_time_current_sec(); spin_lock(&lfsck->li_lock); @@ -823,8 +834,12 @@ static int lfsck_namespace_prep(const struct lu_env *env, } } spin_unlock(&lfsck->li_lock); - up_write(&com->lc_sem); + + CDEBUG(D_LFSCK, "%s: namespace LFSCK prep done, start pos ["LPU64", " + DFID", "LPX64"]\n", lfsck_lfsck2name(lfsck), pos->lp_oit_cookie, + PFID(&pos->lp_dir_parent), pos->lp_dir_cookie); + return 0; } @@ -859,6 +874,7 @@ static int lfsck_namespace_exec_dir(const struct lu_env *env, bool locked = false; bool remove; bool newdata; + bool log = false; int count = 0; int rc; ENTRY; @@ -947,6 +963,7 @@ again: nodata: if (bk->lb_param & LPF_DRYRUN) { ns->ln_linkea_repaired++; + log = true; repaired = true; goto record; } @@ -980,6 +997,7 @@ nodata: count = ldata.ld_leh->leh_reccount; ns->ln_linkea_repaired++; + log = true; repaired = true; } else { GOTO(stop, rc); @@ -1006,6 +1024,13 @@ record: dt_trans_stop(env, lfsck->li_next, handle); handle = NULL; + + if (log) + CDEBUG(D_LFSCK, "%s: namespace LFSCK repaired " + "linkEA for the object: "DFID", parent " + DFID", name %.*s\n", + lfsck_lfsck2name(lfsck), PFID(cfid), PFID(pfid), + ent->lde_namelen, ent->lde_name); } ns->ln_mlinked_checked++; @@ -1023,6 +1048,11 @@ stop: out: if (rc < 0) { + CDEBUG(D_LFSCK, "%s: namespace LFSCK exec_dir failed, " + "parent "DFID", child name %.*s, child FID "DFID + ": rc = %d\n", lfsck_lfsck2name(lfsck), PFID(pfid), + ent->lde_namelen, ent->lde_name, PFID(cfid), rc); + ns->ln_items_failed++; if (lfsck_pos_is_zero(&ns->ln_pos_first_inconsistent)) lfsck_pos_fill(env, lfsck, @@ -1055,7 +1085,6 @@ static int lfsck_namespace_post(const struct lu_env *env, int rc; down_write(&com->lc_sem); - spin_lock(&lfsck->li_lock); if (!init) ns->ln_pos_last_checkpoint = lfsck->li_pos_current; @@ -1092,8 +1121,11 @@ static int lfsck_namespace_post(const struct lu_env *env, } rc = lfsck_namespace_store(env, com, false); - up_write(&com->lc_sem); + + CDEBUG(D_LFSCK, "%s: namespace LFSCK post done: rc = %d\n", + lfsck_lfsck2name(lfsck), rc); + return rc; } @@ -1359,6 +1391,9 @@ static int lfsck_namespace_double_scan_main(void *args) __u8 flags = 0; ENTRY; + CDEBUG(D_LFSCK, "%s: namespace LFSCK phase2 scan start\n", + lfsck_lfsck2name(lfsck)); + com->lc_new_checked = 0; com->lc_new_scanned = 0; com->lc_time_last_checkpoint = cfs_time_current(); @@ -1496,6 +1531,9 @@ out: ns->ln_status = LS_FAILED; } + CDEBUG(D_LFSCK, "%s: namespace LFSCK phase2 scan finished, status %d: " + "rc = %d\n", lfsck_lfsck2name(lfsck), ns->ln_status, rc); + rc = lfsck_namespace_store(env, com, false); up_write(&com->lc_sem); if (atomic_dec_and_test(&lfsck->li_double_scan_count)) @@ -1521,22 +1559,23 @@ static int lfsck_namespace_double_scan(const struct lu_env *env, lta = lfsck_thread_args_init(lfsck, com, NULL); if (IS_ERR(lta)) - RETURN(PTR_ERR(lta)); + GOTO(out, rc = PTR_ERR(lta)); atomic_inc(&lfsck->li_double_scan_count); task = kthread_run(lfsck_namespace_double_scan_main, lta, "lfsck_namespace"); if (IS_ERR(task)) { - rc = PTR_ERR(task); - CERROR("%s: cannot start LFSCK namespace thread: rc = %d\n", - lfsck_lfsck2name(lfsck), rc); atomic_dec(&lfsck->li_double_scan_count); lfsck_thread_args_fini(lta); - } else { - rc = 0; + GOTO(out, rc = PTR_ERR(task)); } - RETURN(rc); + RETURN(0); + +out: + CERROR("%s: cannot start LFSCK namespace thread: rc = %d\n", + lfsck_lfsck2name(lfsck), rc); + return rc; } static int lfsck_namespace_in_notify(const struct lu_env *env, @@ -1638,7 +1677,7 @@ int lfsck_namespace_setup(const struct lu_env *env, spin_unlock(&lfsck->li_lock); break; default: - CERROR("%s: unknown lfsck_namespace status: rc = %u\n", + CERROR("%s: unknown lfsck_namespace status %d\n", lfsck_lfsck2name(lfsck), ns->ln_status); /* fall through */ case LS_SCANNING_PHASE1: @@ -1662,7 +1701,10 @@ int lfsck_namespace_setup(const struct lu_env *env, out: if (root != NULL && !IS_ERR(root)) lu_object_put(env, &root->do_lu); - if (rc != 0) + if (rc != 0) { lfsck_component_cleanup(env, com); + CERROR("%s: fail to init namespace LFSCK component: rc = %d\n", + lfsck_lfsck2name(lfsck), rc); + } return rc; } diff --git a/lustre/ofd/ofd_io.c b/lustre/ofd/ofd_io.c index 599e59f..3d7e60a 100644 --- a/lustre/ofd/ofd_io.c +++ b/lustre/ofd/ofd_io.c @@ -270,16 +270,8 @@ static void ofd_add_inconsistency_item(const struct lu_env *env, bool wakeup = false; OBD_ALLOC_PTR(oii); - if (oii == NULL) { - CERROR("%s: cannot alloc memory for verify OST-object " - "consistency for "DFID", client given PFID "DFID - ", local stored PFID "DFID"\n", - ofd_name(ofd), PFID(&fo->ofo_header.loh_fid), - oa->o_parent_seq, oa->o_parent_oid, oa->o_stripe_idx, - PFID(&fo->ofo_pfid)); - + if (oii == NULL) return; - } INIT_LIST_HEAD(&oii->oii_list); lu_object_get(&fo->ofo_obj.do_lu); diff --git a/lustre/osd-ldiskfs/osd_handler.c b/lustre/osd-ldiskfs/osd_handler.c index 430bb60..7fa5a98 100644 --- a/lustre/osd-ldiskfs/osd_handler.c +++ b/lustre/osd-ldiskfs/osd_handler.c @@ -41,7 +41,7 @@ * Pravin Shelar : Added fid in dirent */ -#define DEBUG_SUBSYSTEM S_MDS +#define DEBUG_SUBSYSTEM S_OSD #include @@ -5006,22 +5006,12 @@ osd_dirent_update(handle_t *jh, struct super_block *sb, LASSERT(de->rec_len >= de->name_len + sizeof(struct osd_fid_pack)); rc = ldiskfs_journal_get_write_access(jh, bh); - if (rc != 0) { - CERROR("%.16s: fail to write access for update dirent: " - "name = %.*s, rc = %d\n", - LDISKFS_SB(sb)->s_es->s_volume_name, - ent->oied_namelen, ent->oied_name, rc); + if (rc != 0) RETURN(rc); - } rec = (struct osd_fid_pack *)(de->name + de->name_len + 1); fid_cpu_to_be((struct lu_fid *)rec->fp_area, fid); rc = ldiskfs_journal_dirty_metadata(jh, bh); - if (rc != 0) - CERROR("%.16s: fail to dirty metadata for update dirent: " - "name = %.*s, rc = %d\n", - LDISKFS_SB(sb)->s_es->s_volume_name, - ent->oied_namelen, ent->oied_name, rc); RETURN(rc); } @@ -5070,13 +5060,8 @@ osd_dirent_reinsert(const struct lu_env *env, handle_t *jh, if (osd_dirent_has_space(de->rec_len, ent->oied_namelen, dir->i_sb->s_blocksize)) { rc = ldiskfs_journal_get_write_access(jh, bh); - if (rc != 0) { - CERROR("%.16s: fail to write access for reinsert " - "dirent: name = %.*s, rc = %d\n", - LDISKFS_SB(inode->i_sb)->s_es->s_volume_name, - ent->oied_namelen, ent->oied_name, rc); + if (rc != 0) RETURN(rc); - } de->name[de->name_len] = 0; rec = (struct osd_fid_pack *)(de->name + de->name_len + 1); @@ -5085,23 +5070,13 @@ osd_dirent_reinsert(const struct lu_env *env, handle_t *jh, de->file_type |= LDISKFS_DIRENT_LUFID; rc = ldiskfs_journal_dirty_metadata(jh, bh); - if (rc != 0) - CERROR("%.16s: fail to dirty metadata for reinsert " - "dirent: name = %.*s, rc = %d\n", - LDISKFS_SB(inode->i_sb)->s_es->s_volume_name, - ent->oied_namelen, ent->oied_name, rc); RETURN(rc); } rc = ldiskfs_delete_entry(jh, dir, de, bh); - if (rc != 0) { - CERROR("%.16s: fail to delete entry for reinsert dirent: " - "name = %.*s, rc = %d\n", - LDISKFS_SB(inode->i_sb)->s_es->s_volume_name, - ent->oied_namelen, ent->oied_name, rc); + if (rc != 0) RETURN(rc); - } dentry = osd_child_dentry_by_inode(env, dir, ent->oied_name, ent->oied_namelen); @@ -5113,10 +5088,11 @@ osd_dirent_reinsert(const struct lu_env *env, handle_t *jh, /* It is too bad, we cannot reinsert the name entry back. * That means we lose it! */ if (rc != 0) - CERROR("%.16s: fail to insert entry for reinsert dirent: " - "name = %.*s, rc = %d\n", + CDEBUG(D_LFSCK, "%.16s: fail to reinsert the dirent, " + "dir = %lu/%u, name = %.*s, "DFID": rc = %d\n", LDISKFS_SB(inode->i_sb)->s_es->s_volume_name, - ent->oied_namelen, ent->oied_name, rc); + dir->i_ino, dir->i_generation, + ent->oied_namelen, ent->oied_name, PFID(fid), rc); RETURN(rc); } @@ -5177,10 +5153,11 @@ again: jh = osd_journal_start_sb(sb, LDISKFS_HT_MISC, credits); if (IS_ERR(jh)) { rc = PTR_ERR(jh); - CERROR("%.16s: fail to start trans for dirent " - "check_repair: credits %d, name %.*s, rc %d\n", - devname, credits, ent->oied_namelen, - ent->oied_name, rc); + CDEBUG(D_LFSCK, "%.16s: fail to start trans for dirent " + "check_repair, dir = %lu/%u, credits = %d, " + "name = %.*s: rc = %d\n", + devname, dir->i_ino, dir->i_generation, credits, + ent->oied_namelen, ent->oied_name, rc); RETURN(rc); } @@ -5224,6 +5201,12 @@ again: if (rc == -ENOENT || rc == -ESTALE) { *attr |= LUDA_IGNORE; rc = 0; + } else { + CDEBUG(D_LFSCK, "%.16s: fail to iget for dirent " + "check_repair, dir = %lu/%u, name = %.*s: " + "rc = %d\n", + devname, dir->i_ino, dir->i_generation, + ent->oied_namelen, ent->oied_name, rc); } GOTO(out_journal, rc); @@ -5265,6 +5248,13 @@ again: rc = osd_dirent_update(jh, sb, ent, fid, bh, de); if (rc == 0) *attr |= LUDA_REPAIR; + else + CDEBUG(D_LFSCK, "%.16s: fail to update FID " + "in the dirent, dir = %lu/%u, " + "name = %.*s, "DFID": rc = %d\n", + devname, dir->i_ino, dir->i_generation, + ent->oied_namelen, ent->oied_name, + PFID(fid), rc); } else { /* Do not repair under dryrun mode. */ if (*attr & LUDA_VERIFY_DRYRUN) { @@ -5291,6 +5281,13 @@ again: fid, bh, de, hlock); if (rc == 0) *attr |= LUDA_REPAIR; + else + CDEBUG(D_LFSCK, "%.16s: fail to append FID " + "after the dirent, dir = %lu/%u, " + "name = %.*s, "DFID": rc = %d\n", + devname, dir->i_ino, dir->i_generation, + ent->oied_namelen, ent->oied_name, + PFID(fid), rc); } } else if (rc == -ENODATA) { /* Do not repair under dryrun mode. */ @@ -5323,6 +5320,13 @@ again: rc = osd_ea_fid_set(info, inode, fid, 0, 0); if (rc == 0) *attr |= LUDA_REPAIR; + else + CDEBUG(D_LFSCK, "%.16s: fail to set LMA for " + "update dirent, dir = %lu/%u, " + "name = %.*s, "DFID": rc = %d\n", + devname, dir->i_ino, dir->i_generation, + ent->oied_namelen, ent->oied_name, + PFID(fid), rc); } else { lu_igif_build(fid, inode->i_ino, inode->i_generation); /* It is probably IGIF object. Only aappend the @@ -5331,6 +5335,13 @@ again: fid, bh, de, hlock); if (rc == 0) *attr |= LUDA_UPGRADE; + else + CDEBUG(D_LFSCK, "%.16s: fail to append IGIF " + "after the dirent, dir = %lu/%u, " + "name = %.*s, "DFID": rc = %d\n", + devname, dir->i_ino, dir->i_generation, + ent->oied_namelen, ent->oied_name, + PFID(fid), rc); } } diff --git a/lustre/osd-ldiskfs/osd_lproc.c b/lustre/osd-ldiskfs/osd_lproc.c index ddaa169..98e857a 100644 --- a/lustre/osd-ldiskfs/osd_lproc.c +++ b/lustre/osd-ldiskfs/osd_lproc.c @@ -38,7 +38,7 @@ * Author: Mikhail Pershin */ -#define DEBUG_SUBSYSTEM S_CLASS +#define DEBUG_SUBSYSTEM S_OSD #include #include diff --git a/lustre/osd-ldiskfs/osd_oi.c b/lustre/osd-ldiskfs/osd_oi.c index 3cb6579..476313e 100644 --- a/lustre/osd-ldiskfs/osd_oi.c +++ b/lustre/osd-ldiskfs/osd_oi.c @@ -40,7 +40,7 @@ * Author: Nikita Danilov */ -#define DEBUG_SUBSYSTEM S_MDS +#define DEBUG_SUBSYSTEM S_OSD #include diff --git a/lustre/osd-ldiskfs/osd_scrub.c b/lustre/osd-ldiskfs/osd_scrub.c index d8a5cc5..031ae90 100644 --- a/lustre/osd-ldiskfs/osd_scrub.c +++ b/lustre/osd-ldiskfs/osd_scrub.c @@ -35,7 +35,7 @@ * Author: Fan Yong */ -#define DEBUG_SUBSYSTEM S_MDS +#define DEBUG_SUBSYSTEM S_LFSCK #include #include @@ -80,6 +80,11 @@ static inline int osd_scrub_has_window(struct osd_scrub *scrub, return scrub->os_pos_current < ooc->ooc_pos_preload + SCRUB_WINDOW_SIZE; } +static inline const char *osd_scrub2name(struct osd_scrub *scrub) +{ + return LDISKFS_SB(osd_scrub2sb(scrub))->s_es->s_volume_name; +} + /** * update/insert/delete the specified OI mapping (@fid @id) according to the ops * @@ -107,8 +112,9 @@ static int osd_scrub_refresh_mapping(struct osd_thread_info *info, osd_dto_credits_noquota[DTO_INDEX_INSERT]); if (IS_ERR(th)) { rc = PTR_ERR(th); - CERROR("%s: fail to start trans for scrub %d: rc = %d\n", - osd_name(dev), ops, rc); + CDEBUG(D_LFSCK, "%s: fail to start trans for scrub op %d " + DFID" => %u/%u: rc = %d\n", osd_name(dev), ops, + PFID(fid), id->oii_ino, id->oii_gen, rc); RETURN(rc); } @@ -171,7 +177,12 @@ static int osd_scrub_refresh_mapping(struct osd_thread_info *info, } ldiskfs_journal_stop(th); - return rc; + if (rc < 0) + CDEBUG(D_LFSCK, "%s: fail to refresh OI map for scrub op %d " + DFID" => %u/%u: rc = %d\n", osd_name(dev), ops, + PFID(fid), id->oii_ino, id->oii_gen, rc); + + RETURN(rc); } /* OI_scrub file ops */ @@ -260,7 +271,8 @@ void osd_scrub_file_reset(struct osd_scrub *scrub, __u8 *uuid, __u64 flags) { struct scrub_file *sf = &scrub->os_file; - CDEBUG(D_LFSCK, "Reset OI scrub file, flags = "LPX64"\n", flags); + CDEBUG(D_LFSCK, "%.16s: reset OI scrub file, flags = "LPX64"\n", + osd_scrub2name(scrub), flags); memcpy(sf->sf_uuid, uuid, 16); sf->sf_status = SS_INIT; sf->sf_flags |= flags; @@ -281,7 +293,6 @@ void osd_scrub_file_reset(struct osd_scrub *scrub, __u8 *uuid, __u64 flags) static int osd_scrub_file_load(struct osd_scrub *scrub) { loff_t pos = 0; - char *name = LDISKFS_SB(osd_scrub2sb(scrub))->s_es->s_volume_name; int len = sizeof(scrub->os_file_disk); int rc; @@ -291,16 +302,18 @@ static int osd_scrub_file_load(struct osd_scrub *scrub) osd_scrub_file_to_cpu(sf, &scrub->os_file_disk); if (sf->sf_magic != SCRUB_MAGIC_V1) { - CWARN("%.16s: invalid scrub magic 0x%x != 0x%x\n,", - name, sf->sf_magic, SCRUB_MAGIC_V1); + CDEBUG(D_LFSCK, "%.16s: invalid scrub magic " + "0x%x != 0x%x\n", osd_scrub2name(scrub), + sf->sf_magic, SCRUB_MAGIC_V1); /* Process it as new scrub file. */ rc = -ENOENT; } else { rc = 0; } } else if (rc != 0) { - CERROR("%.16s: fail to load scrub file, expected = %d, " - "rc = %d\n", name, len, rc); + CDEBUG(D_LFSCK, "%.16s: fail to load scrub file, " + "expected = %d: rc = %d\n", + osd_scrub2name(scrub), len, rc); if (rc > 0) rc = -EFAULT; } else { @@ -326,8 +339,8 @@ int osd_scrub_file_store(struct osd_scrub *scrub) jh = osd_journal_start_sb(osd_sb(dev), LDISKFS_HT_MISC, credits); if (IS_ERR(jh)) { rc = PTR_ERR(jh); - CERROR("%.16s: fail to start trans for scrub store, rc = %d\n", - LDISKFS_SB(osd_scrub2sb(scrub))->s_es->s_volume_name,rc); + CDEBUG(D_LFSCK, "%.16s: fail to start trans for scrub store: " + "rc = %d\n", osd_scrub2name(scrub), rc); return rc; } @@ -336,10 +349,10 @@ int osd_scrub_file_store(struct osd_scrub *scrub) len, 0, &pos, jh); ldiskfs_journal_stop(jh); if (rc != 0) - CERROR("%.16s: fail to store scrub file, expected = %d, " - "rc = %d\n", - LDISKFS_SB(osd_scrub2sb(scrub))->s_es->s_volume_name, - len, rc); + CDEBUG(D_LFSCK, "%.16s: fail to store scrub file, " + "expected = %d: rc = %d\n", + osd_scrub2name(scrub), len, rc); + scrub->os_time_last_checkpoint = cfs_time_current(); scrub->os_time_next_checkpoint = scrub->os_time_last_checkpoint + cfs_time_seconds(SCRUB_CHECKPOINT_INTERVAL); @@ -376,9 +389,8 @@ osd_scrub_convert_ff(struct osd_thread_info *info, struct osd_device *dev, osd_dto_credits_noquota[DTO_XATTR_SET] * 3); if (IS_ERR(jh)) { rc = PTR_ERR(jh); - CERROR("%s: fail to start trans for convert ff: "DFID - ": rc = %d\n", - osd_name(dev), PFID(fid), rc); + CDEBUG(D_LFSCK, "%s: fail to start trans for convert ff " + DFID": rc = %d\n", osd_name(dev), PFID(fid), rc); RETURN(rc); } @@ -420,6 +432,9 @@ osd_scrub_convert_ff(struct osd_thread_info *info, struct osd_device *dev, stop: ldiskfs_journal_stop(jh); + if (rc < 0) + CDEBUG(D_LFSCK, "%s: fail to convert ff "DFID": rc = %d\n", + osd_name(dev), PFID(fid), rc); return rc; } @@ -735,10 +750,6 @@ static void osd_scrub_post(struct osd_scrub *scrub, int result) sf->sf_run_time += cfs_duration_sec(cfs_time_current() + HALF_SEC - scrub->os_time_last_checkpoint); result = osd_scrub_file_store(scrub); - if (result < 0) - CERROR("%.16s: fail to osd_scrub_post, rc = %d\n", - LDISKFS_SB(osd_scrub2sb(scrub))->s_es->s_volume_name, - result); up_write(&scrub->os_rwsem); EXIT; @@ -901,8 +912,9 @@ static int osd_iit_iget(struct osd_thread_info *info, struct osd_device *dev, if (rc == -ENOENT || rc == -ESTALE) RETURN(SCRUB_NEXT_CONTINUE); - CERROR("%.16s: fail to read inode, ino# = %u, rc = %d\n", - LDISKFS_SB(sb)->s_es->s_volume_name, pos, rc); + CDEBUG(D_LFSCK, "%.16s: fail to read inode, ino# = %u: " + "rc = %d\n", LDISKFS_SB(sb)->s_es->s_volume_name, + pos, rc); RETURN(rc); } @@ -1054,8 +1066,8 @@ static int osd_scrub_exec(struct osd_thread_info *info, struct osd_device *dev, rc = osd_scrub_checkpoint(scrub); if (rc != 0) { - CERROR("%.16s: fail to checkpoint, pos = %u, rc = %d\n", - LDISKFS_SB(param->sb)->s_es->s_volume_name, + CDEBUG(D_LFSCK, "%.16s: fail to checkpoint, pos = %u: " + "rc = %d\n", osd_scrub2name(scrub), scrub->os_pos_current, rc); /* Continue, as long as the scrub itself can go ahead. */ } @@ -1152,7 +1164,7 @@ static int osd_inode_iteration(struct osd_thread_info *info, param.gbase = 1 + param.bg * LDISKFS_INODES_PER_GROUP(param.sb); param.bitmap = ldiskfs_read_inode_bitmap(param.sb, param.bg); if (param.bitmap == NULL) { - CERROR("%.16s: fail to read bitmap for %u, " + CDEBUG(D_LFSCK, "%.16s: fail to read bitmap for %u, " "scrub will stop, urgent mode\n", LDISKFS_SB(param.sb)->s_es->s_volume_name, (__u32)param.bg); @@ -1206,10 +1218,6 @@ static int osd_otable_it_preload(const struct lu_env *env, if (rc == SCRUB_IT_ALL) it->ooi_all_cached = 1; - CDEBUG(D_LFSCK, "OSD pre-loaded: max = %u, preload = %u, rc = %d\n", - le32_to_cpu(LDISKFS_SB(osd_sb(dev))->s_es->s_inodes_count), - ooc->ooc_pos_preload, rc); - if (scrub->os_waiting && osd_scrub_has_window(scrub, ooc)) { spin_lock(&scrub->os_lock); scrub->os_waiting = 0; @@ -1226,21 +1234,20 @@ static int osd_scrub_main(void *args) struct osd_device *dev = (struct osd_device *)args; struct osd_scrub *scrub = &dev->od_scrub; struct ptlrpc_thread *thread = &scrub->os_thread; - struct super_block *sb = osd_sb(dev); int rc; ENTRY; rc = lu_env_init(&env, LCT_LOCAL); if (rc != 0) { - CERROR("%.16s: OI scrub, fail to init env, rc = %d\n", - LDISKFS_SB(sb)->s_es->s_volume_name, rc); + CDEBUG(D_LFSCK, "%.16s: OI scrub fail to init env: rc = %d\n", + osd_scrub2name(scrub), rc); GOTO(noenv, rc); } rc = osd_scrub_prep(dev); if (rc != 0) { - CERROR("%.16s: OI scrub, fail to scrub prep, rc = %d\n", - LDISKFS_SB(sb)->s_es->s_volume_name, rc); + CDEBUG(D_LFSCK, "%.16s: OI scrub fail to scrub prep: rc = %d\n", + osd_scrub2name(scrub), rc); GOTO(out, rc); } @@ -1258,8 +1265,9 @@ static int osd_scrub_main(void *args) scrub->os_pos_current = ooc->ooc_pos_preload; } - CDEBUG(D_LFSCK, "OI scrub: flags = 0x%x, pos = %u\n", - scrub->os_start_flags, scrub->os_pos_current); + CDEBUG(D_LFSCK, "%.16s: OI scrub start, flags = 0x%x, pos = %u\n", + osd_scrub2name(scrub), scrub->os_start_flags, + scrub->os_pos_current); rc = osd_inode_iteration(osd_oti_get(&env), dev, ~0U, false); if (unlikely(rc == SCRUB_IT_CRASH)) @@ -1268,8 +1276,8 @@ static int osd_scrub_main(void *args) post: osd_scrub_post(scrub, rc); - CDEBUG(D_LFSCK, "OI scrub: stop, rc = %d, pos = %u\n", - rc, scrub->os_pos_current); + CDEBUG(D_LFSCK, "%.16s: OI scrub: stop, pos = %u: rc = %d\n", + osd_scrub2name(scrub), scrub->os_pos_current, rc); out: while (!list_empty(&scrub->os_inconsistent_items)) { @@ -1457,9 +1465,6 @@ osd_ios_lookup_one_len(const char *name, struct dentry *parent, int namelen) { struct dentry *dentry; - CDEBUG(D_LFSCK, "init lookup one: parent = %.*s, name = %.*s\n", - parent->d_name.len, parent->d_name.name, namelen, name); - dentry = ll_lookup_one_len(name, parent, namelen); if (!IS_ERR(dentry) && dentry->d_inode == NULL) { dput(dentry); @@ -1509,11 +1514,13 @@ osd_ios_scan_one(struct osd_thread_info *info, struct osd_device *dev, int rc; ENTRY; - CDEBUG(D_LFSCK, "init scan one: ino = %ld\n", inode->i_ino); - rc = osd_get_lma(info, inode, &info->oti_obj_dentry, lma); - if (rc != 0 && rc != -ENODATA) + if (rc != 0 && rc != -ENODATA) { + CDEBUG(D_LFSCK, "%s: fail to get lma for init OI scrub: " + "rc = %d\n", osd_name(dev), rc); + RETURN(rc); + } osd_id_gen(id, inode->i_ino, inode->i_generation); if (rc == -ENODATA) { @@ -1522,8 +1529,12 @@ osd_ios_scan_one(struct osd_thread_info *info, struct osd_device *dev, else tfid = *fid; rc = osd_ea_fid_set(info, inode, &tfid, 0, 0); - if (rc != 0) + if (rc != 0) { + CDEBUG(D_LFSCK, "%s: fail to set LMA for init OI " + "scrub: rc = %d\n", osd_name(dev), rc); + RETURN(rc); + } } else { if (lma->lma_compat & LMAC_NOT_IN_OI) RETURN(0); @@ -1590,7 +1601,7 @@ static int osd_ios_lf_fill(void *buf, const char *name, int namelen, scrub->os_lf_scanned++; child = osd_ios_lookup_one_len(name, parent, namelen); if (IS_ERR(child)) { - CWARN("%s: cannot lookup child '%.*s': rc = %d\n", + CDEBUG(D_LFSCK, "%s: cannot lookup child '%.*s': rc = %d\n", osd_name(dev), namelen, name, (int)PTR_ERR(child)); RETURN(0); } @@ -1600,8 +1611,8 @@ static int osd_ios_lf_fill(void *buf, const char *name, int namelen, rc = osd_ios_new_item(dev, child, osd_ios_general_scan, osd_ios_lf_fill); if (rc != 0) - CWARN("%s: cannot add child '%.*s': rc = %d\n", - osd_name(dev), namelen, name, rc); + CDEBUG(D_LFSCK, "%s: cannot add child '%.*s': " + "rc = %d\n", osd_name(dev), namelen, name, rc); GOTO(put, rc); } @@ -1616,8 +1627,9 @@ static int osd_ios_lf_fill(void *buf, const char *name, int namelen, "/lost+found.\n", namelen, name, PFID(fid)); scrub->os_lf_repaired++; } else { - CWARN("%s: cannot rename for '%.*s' "DFID": rc = %d\n", - osd_name(dev), namelen, name, PFID(fid), rc); + CDEBUG(D_LFSCK, "%s: cannot rename for '%.*s' " + DFID": rc = %d\n", + osd_name(dev), namelen, name, PFID(fid), rc); } } @@ -2029,7 +2041,7 @@ again: if (IS_ERR(task)) { rc = PTR_ERR(task); CERROR("%.16s: cannot start iteration thread: rc = %d\n", - LDISKFS_SB(osd_sb(dev))->s_es->s_volume_name, rc); + osd_scrub2name(scrub), rc); RETURN(rc); } diff --git a/lustre/osd-zfs/osd_lproc.c b/lustre/osd-zfs/osd_lproc.c index f19ed11..f3a662c 100644 --- a/lustre/osd-zfs/osd_lproc.c +++ b/lustre/osd-zfs/osd_lproc.c @@ -41,7 +41,7 @@ * Author: Mike Pershin */ -#define DEBUG_SUBSYSTEM S_CLASS +#define DEBUG_SUBSYSTEM S_OSD #include #include diff --git a/lustre/tests/sanity-lfsck.sh b/lustre/tests/sanity-lfsck.sh index e22f841..29c768f 100644 --- a/lustre/tests/sanity-lfsck.sh +++ b/lustre/tests/sanity-lfsck.sh @@ -514,7 +514,7 @@ test_6a() { local POS1=$($SHOW_NAMESPACE | awk '/^latest_start_position/ { print $2 }' | tr -d ',') - [ $POS0 -lt $POS1 ] || + [[ $POS0 -lt $POS1 ]] || error "(7) Expect larger than: $POS0, but got $POS1" do_facet $SINGLEMDS $LCTL set_param fail_loc=0 fail_val=0 @@ -572,10 +572,10 @@ test_6b() { awk '/^latest_start_position/ { print $4 }') if [ "$D_POS0" == "N/A" -o "$D_POS1" == "N/A" ]; then - [ $O_POS0 -lt $O_POS1 ] || + [[ $O_POS0 -lt $O_POS1 ]] || error "(7.1) $O_POS1 is not larger than $O_POS0" else - [ $D_POS0 -lt $D_POS1 ] || + [[ $D_POS0 -lt $D_POS1 ]] || error "(7.2) $D_POS1 is not larger than $D_POS0" fi -- 1.8.3.1