From f98d4b3cfd294ad465ec0f1d9fcdf7721f36605a Mon Sep 17 00:00:00 2001 From: Oguzhan Ozmen Date: Fri, 20 Sep 2024 14:56:12 -0400 Subject: [PATCH] RGW: add src/dest object info to fetch_remote_obj()'s debug log events Signed-off-by: Oguzhan Ozmen --- src/rgw/driver/rados/rgw_rados.cc | 37 +++++++++++++++++++++---------- 1 file changed, 25 insertions(+), 12 deletions(-) diff --git a/src/rgw/driver/rados/rgw_rados.cc b/src/rgw/driver/rados/rgw_rados.cc index e2f64334638..dbcd078eba3 100644 --- a/src/rgw/driver/rados/rgw_rados.cc +++ b/src/rgw/driver/rados/rgw_rados.cc @@ -4199,6 +4199,10 @@ int RGWRados::fetch_remote_obj(RGWObjectCtx& dest_obj_ctx, obj_time_weight set_mtime_weight; set_mtime_weight.high_precision = high_precision_time; int ret; + const string fetched_obj = fmt::format( + "object(src={}:{}, dest={}:{})", src_obj.bucket.bucket_id, src_obj.key.name, + dest_obj.bucket.bucket_id, dest_obj.key.name + ); // use an empty owner until we decode RGW_ATTR_ACL ACLOwner owner; @@ -4256,7 +4260,8 @@ int RGWRados::fetch_remote_obj(RGWObjectCtx& dest_obj_ctx, &override_owner, &ptail_rule); if (ret < 0) { - ldpp_dout(rctx.dpp, 5) << "Aborting fetch: source object filter returned ret=" << ret << dendl; + ldpp_dout(rctx.dpp, 5) << "Aborting fetch: source " << fetched_obj + << " filter returned ret=" << ret << dendl; return ret; } @@ -4325,7 +4330,8 @@ int RGWRados::fetch_remote_obj(RGWObjectCtx& dest_obj_ctx, &accounted_size, nullptr, nullptr, rctx.y); if (ret < 0) { if (ret == -EIO && tries < NUM_ENPOINT_IOERROR_RETRIES - 1) { - ldpp_dout(rctx.dpp, 20) << __func__ << "(): failed to fetch object from remote. retries=" << tries << dendl; + ldpp_dout(rctx.dpp, 20) << __func__ << "(): failed to fetch " << fetched_obj + << " from remote. retries=" << tries << dendl; continue; } goto set_err_state; @@ -4338,8 +4344,9 @@ int RGWRados::fetch_remote_obj(RGWObjectCtx& dest_obj_ctx, } if (cb.get_data_len() != accounted_size) { ret = -EIO; - ldpp_dout(rctx.dpp, 0) << "ERROR: object truncated during fetching, expected " - << accounted_size << " bytes but received " << cb.get_data_len() << dendl; + ldpp_dout(rctx.dpp, 0) << "ERROR: " << fetched_obj + << " truncated during fetching, expected " << accounted_size + << " bytes but received " << cb.get_data_len() << dendl; goto set_err_state; } @@ -4363,7 +4370,7 @@ int RGWRados::fetch_remote_obj(RGWObjectCtx& dest_obj_ctx, accounted_size = info.orig_size; } catch (const buffer::error&) { ldpp_dout(rctx.dpp, 0) << "ERROR: could not decode compression attr for " - "replicated object " << dest_obj << dendl; + "replicated " << fetched_obj << dendl; // decode error isn't fatal, but we might put the wrong size in the index } } @@ -4482,8 +4489,8 @@ int RGWRados::fetch_remote_obj(RGWObjectCtx& dest_obj_ctx, if (verifier_etag != trimmed_etag) { ret = -EIO; - ldpp_dout(rctx.dpp, 0) << "ERROR: source and destination objects don't match. Expected etag:" - << trimmed_etag << " Computed etag:" << verifier_etag << dendl; + ldpp_dout(rctx.dpp, 0) << "ERROR: source and destination objects don't match: " << fetched_obj + << ". Expected etag:" << trimmed_etag << " Computed etag:" << verifier_etag << dendl; goto set_err_state; } } @@ -4500,28 +4507,34 @@ int RGWRados::fetch_remote_obj(RGWObjectCtx& dest_obj_ctx, } if (copy_if_newer && canceled) { - ldpp_dout(rctx.dpp, 20) << "raced with another write of obj: " << dest_obj << dendl; + ldpp_dout(rctx.dpp, 20) << "raced with another write of obj: " << fetched_obj << dendl; dest_obj_ctx.invalidate(dest_obj); /* object was overwritten */ ret = get_obj_state(rctx.dpp, &dest_obj_ctx, dest_bucket_info, stat_dest_obj, &dest_state, &manifest, stat_follow_olh, rctx.y); if (ret < 0) { - ldpp_dout(rctx.dpp, 0) << "ERROR: " << __func__ << ": get_err_state() returned ret=" << ret << dendl; + ldpp_dout(rctx.dpp, 0) << "ERROR: " << __func__ << ": get_err_state() returned ret=" << ret + << " " << fetched_obj << dendl; goto set_err_state; } dest_mtime_weight.init(dest_state); dest_mtime_weight.high_precision = high_precision_time; if (!dest_state->exists || dest_mtime_weight < set_mtime_weight) { - ldpp_dout(rctx.dpp, 20) << "retrying writing object mtime=" << set_mtime << " dest_state->mtime=" << dest_state->mtime << " dest_state->exists=" << dest_state->exists << dendl; + ldpp_dout(rctx.dpp, 20) << "retrying writing " << fetched_obj + << " mtime=" << set_mtime << " dest_state->mtime=" << dest_state->mtime + << " dest_state->exists=" << dest_state->exists << dendl; continue; } else { - ldpp_dout(rctx.dpp, 20) << "not retrying writing object mtime=" << set_mtime << " dest_state->mtime=" << dest_state->mtime << " dest_state->exists=" << dest_state->exists << dendl; + ldpp_dout(rctx.dpp, 20) << "not retrying writing " << fetched_obj + << " mtime=" << set_mtime << " dest_state->mtime=" << dest_state->mtime + << " dest_state->exists=" << dest_state->exists << dendl; } } break; } if (i == MAX_COMPLETE_RETRY) { - ldpp_dout(rctx.dpp, 0) << "ERROR: retried object completion too many times, something is wrong!" << dendl; + ldpp_dout(rctx.dpp, 0) << "ERROR: retried " << fetched_obj + << " completion too many times, something is wrong!" << dendl; ret = -EIO; goto set_err_state; } -- 2.39.5