From 3793a29486a05da3d5b572d7708987dd6f69eb3e Mon Sep 17 00:00:00 2001 From: "J. Eric Ivancich" Date: Tue, 26 Apr 2022 12:35:05 -0400 Subject: [PATCH] rgw: use dpp in bitx logging code This updates the bitx logging code to use the logging provided by DoutPrefixProvider. Signed-off-by: J. Eric Ivancich --- src/rgw/rgw_rados.cc | 57 ++++++++++++++++++++++---------------------- 1 file changed, 29 insertions(+), 28 deletions(-) diff --git a/src/rgw/rgw_rados.cc b/src/rgw/rgw_rados.cc index b9375d50ce1..a9cd4d63a94 100644 --- a/src/rgw/rgw_rados.cc +++ b/src/rgw/rgw_rados.cc @@ -103,7 +103,8 @@ using namespace std; using namespace librados; -#define ldout_bitx(_bitx, _ctx, _level) if(_bitx) { ldout(_ctx, 0) << "BITX: " +#define ldout_bitx(_bitx, _dpp, _level) if(_bitx) { ldpp_dout(_dpp, 0) << "BITX: " +#define ldout_bitx_c(_bitx, _ctx, _level) if(_bitx) { ldout(_ctx, 0) << "BITX: " #define dendl_bitx dendl ; } static string shadow_ns = "shadow"; @@ -896,11 +897,11 @@ void RGWIndexCompletionManager::process() r = store->guard_reshard(&dpp, &bs, c->obj, bucket_info, [&](RGWRados::BucketShard *bs) -> int { const bool bitx = ctx()->_conf->rgw_bucket_index_transaction_instrumentation; - ldout_bitx(bitx, ctx(), 10) << + ldout_bitx(bitx, &dpp, 10) << "ENTERING " << __func__ << ": bucket-shard=" << bs << " obj=" << c->obj << " tag=" << c->tag << " op=" << c->op << ", remove_objs=" << c->remove_objs << dendl_bitx; - ldout_bitx(bitx, ctx(), 25) << + ldout_bitx(bitx, &dpp, 25) << "BACKTRACE: " << __func__ << ": " << ClibBackTrace(1) << dendl_bitx; librados::ObjectWriteOperation o; @@ -908,7 +909,7 @@ void RGWIndexCompletionManager::process() cls_rgw_bucket_complete_op(o, c->op, c->tag, c->ver, c->key, c->dir_meta, &c->remove_objs, c->log_op, c->bilog_op, &c->zones_trace); int ret = bs->bucket_obj.operate(&dpp, &o, null_yield); - ldout_bitx(bitx, ctx(), 10) << + ldout_bitx(bitx, &dpp, 10) << "EXITING " << __func__ << ": ret=" << dendl_bitx; return ret; }); @@ -8362,8 +8363,8 @@ int RGWRados::cls_obj_prepare_op(const DoutPrefixProvider *dpp, BucketShard& bs, rgw_obj& obj, uint16_t bilog_flags, optional_yield y, rgw_zone_set *_zones_trace) { const bool bitx = cct->_conf->rgw_bucket_index_transaction_instrumentation; - ldout_bitx(bitx, cct, 10) << "ENTERING " << __func__ << ": bucket-shard=" << bs << " obj=" << obj << " tag=" << tag << " op=" << op << dendl_bitx; - ldout_bitx(bitx, cct, 25) << "BACKTRACE: " << __func__ << ": " << ClibBackTrace(0) << dendl_bitx; + ldout_bitx(bitx, dpp, 10) << "ENTERING " << __func__ << ": bucket-shard=" << bs << " obj=" << obj << " tag=" << tag << " op=" << op << dendl_bitx; + ldout_bitx(bitx, dpp, 25) << "BACKTRACE: " << __func__ << ": " << ClibBackTrace(0) << dendl_bitx; rgw_zone_set zones_trace; if (_zones_trace) { @@ -8376,7 +8377,7 @@ int RGWRados::cls_obj_prepare_op(const DoutPrefixProvider *dpp, BucketShard& bs, cls_rgw_guard_bucket_resharding(o, -ERR_BUSY_RESHARDING); cls_rgw_bucket_prepare_op(o, op, tag, key, obj.key.get_loc(), svc.zone->get_zone().log_data, bilog_flags, zones_trace); int ret = bs.bucket_obj.operate(dpp, &o, y); - ldout_bitx(bitx, cct, 10) << "EXITING " << __func__ << ": ret=" << ret << dendl_bitx; + ldout_bitx(bitx, dpp, 10) << "EXITING " << __func__ << ": ret=" << ret << dendl_bitx; return ret; } @@ -8386,10 +8387,10 @@ int RGWRados::cls_obj_complete_op(BucketShard& bs, const rgw_obj& obj, RGWModify list *remove_objs, uint16_t bilog_flags, rgw_zone_set *_zones_trace) { const bool bitx = cct->_conf->rgw_bucket_index_transaction_instrumentation; - ldout_bitx(bitx, cct, 10) << "ENTERING " << __func__ << ": bucket-shard=" << bs << + ldout_bitx_c(bitx, cct, 10) << "ENTERING " << __func__ << ": bucket-shard=" << bs << " obj=" << obj << " tag=" << tag << " op=" << op << ", remove_objs=" << (remove_objs ? *remove_objs : std::list()) << dendl_bitx; - ldout_bitx(bitx, cct, 25) << "BACKTRACE: " << __func__ << ": " << ClibBackTrace(0) << dendl_bitx; + ldout_bitx_c(bitx, cct, 25) << "BACKTRACE: " << __func__ << ": " << ClibBackTrace(0) << dendl_bitx; ObjectWriteOperation o; rgw_bucket_dir_entry_meta dir_meta; @@ -8416,7 +8417,7 @@ int RGWRados::cls_obj_complete_op(BucketShard& bs, const rgw_obj& obj, RGWModify int ret = bs.bucket_obj.aio_operate(arg->rados_completion, &o); completion->release(); /* can't reference arg here, as it might have already been released */ - ldout_bitx(bitx, cct, 10) << "EXITING " << __func__ << ": ret=" << ret << dendl_bitx; + ldout_bitx_c(bitx, cct, 10) << "EXITING " << __func__ << ": ret=" << ret << dendl_bitx; return ret; } @@ -8521,7 +8522,7 @@ int RGWRados::cls_bucket_list_ordered(const DoutPrefixProvider *dpp, * few results, perhaps due to filtering or to a series of * namespaced entries */ - ldout_bitx(bitx, cct, 10) << "ENTERING " << __func__ << ": " << bucket_info.bucket << + ldout_bitx(bitx, dpp, 10) << "ENTERING " << __func__ << ": " << bucket_info.bucket << " start_after=\"" << start_after.to_string() << "\", prefix=\"" << prefix << ", delimiter=\"" << delimiter << @@ -8531,7 +8532,7 @@ int RGWRados::cls_bucket_list_ordered(const DoutPrefixProvider *dpp, ", expansion_factor=" << expansion_factor << ", force_check_filter is " << (force_check_filter ? "set" : "unset") << dendl_bitx; - ldout_bitx(bitx, cct, 25) << "BACKTRACE: " << __func__ << ": " << ClibBackTrace(0) << dendl_bitx; + ldout_bitx(bitx, dpp, 25) << "BACKTRACE: " << __func__ << ": " << ClibBackTrace(0) << dendl_bitx; m.clear(); @@ -8695,7 +8696,7 @@ int RGWRados::cls_bucket_list_ordered(const DoutPrefixProvider *dpp, * well. */ librados::IoCtx sub_ctx; sub_ctx.dup(ioctx); - ldout_bitx(bitx, cct, 20) << "INFO: " << __func__ << + ldout_bitx(bitx, dpp, 20) << "INFO: " << __func__ << " calling check_disk_state bucket=" << bucket_info.bucket << " entry=" << dirent.key << dendl_bitx; r = check_disk_state(dpp, sub_ctx, bucket_info, dirent, dirent, @@ -8758,7 +8759,7 @@ int RGWRados::cls_bucket_list_ordered(const DoutPrefixProvider *dpp, AioCompletion *c = librados::Rados::aio_create_completion(nullptr, nullptr); - ldout_bitx(bitx, cct, 10) << "INFO: " << __func__ << + ldout_bitx(bitx, dpp, 10) << "INFO: " << __func__ << ": doing dir_suggest on " << miter.first << dendl_bitx; ioctx.aio_operate(miter.first, c, &o); c->release(); @@ -8794,7 +8795,7 @@ int RGWRados::cls_bucket_list_ordered(const DoutPrefixProvider *dpp, ": returning, last_entry NOT SET" << dendl; } - ldout_bitx(bitx, cct, 10) << "EXITING " << __func__ << dendl_bitx; + ldout_bitx(bitx, dpp, 10) << "EXITING " << __func__ << dendl_bitx; return 0; } @@ -8830,14 +8831,14 @@ int RGWRados::cls_bucket_list_unordered(const DoutPrefixProvider *dpp, RGWBucketListNameFilter force_check_filter) { const bool bitx = cct->_conf->rgw_bucket_index_transaction_instrumentation; - ldout_bitx(bitx, cct, 10) << "ENTERING " << __func__ << ": " << bucket_info.bucket << + ldout_bitx(bitx, dpp, 10) << "ENTERING " << __func__ << ": " << bucket_info.bucket << " start_after=\"" << start_after << "\", prefix=\"" << prefix << "\", shard_id=" << shard_id << "\", num_entries=" << num_entries << ", list_versions=" << list_versions << (force_check_filter ? "set" : "unset") << dendl_bitx; - ldout_bitx(bitx, cct, 25) << "BACKTRACE: " << __func__ << ": " << ClibBackTrace(0) << dendl_bitx; + ldout_bitx(bitx, dpp, 25) << "BACKTRACE: " << __func__ << ": " << ClibBackTrace(0) << dendl_bitx; ent_list.clear(); static MultipartMetaFilter multipart_meta_filter; @@ -8938,7 +8939,7 @@ int RGWRados::cls_bucket_list_unordered(const DoutPrefixProvider *dpp, * and if the tags are old we need to do cleanup as well. */ librados::IoCtx sub_ctx; sub_ctx.dup(ioctx); - ldout_bitx(bitx, cct, 20) << "INFO: " << __func__ << + ldout_bitx(bitx, dpp, 20) << "INFO: " << __func__ << ": calling check_disk_state bucket=" << bucket_info.bucket << " entry=" << dirent.key << dendl_bitx; r = check_disk_state(dpp, sub_ctx, bucket_info, dirent, dirent, updates[oid], y); @@ -8993,7 +8994,7 @@ check_updates: // we don't care if we lose suggested updates, send them off blindly AioCompletion *c = librados::Rados::aio_create_completion(nullptr, nullptr); - ldout_bitx(bitx, cct, 10) << "INFO: " << __func__ << + ldout_bitx(bitx, dpp, 10) << "INFO: " << __func__ << " doing dir_suggest on " << miter->first << dendl_bitx; ioctx.aio_operate(miter->first, c, &o); c->release(); @@ -9004,7 +9005,7 @@ check_updates: *last_entry = last_added_entry; } - ldout_bitx(bitx, cct, 10) << "EXITING " << __func__ << dendl_bitx; + ldout_bitx(bitx, dpp, 10) << "EXITING " << __func__ << dendl_bitx; return 0; } // RGWRados::cls_bucket_list_unordered @@ -9144,7 +9145,7 @@ int RGWRados::check_disk_state(const DoutPrefixProvider *dpp, optional_yield y) { const bool bitx = cct->_conf->rgw_bucket_index_transaction_instrumentation; - ldout_bitx(bitx, cct, 10) << "ENTERING " << __func__ << ": bucket=" << + ldout_bitx(bitx, dpp, 10) << "ENTERING " << __func__ << ": bucket=" << bucket_info.bucket << " dir_entry=" << list_state.key << dendl_bitx; std::unique_ptr bucket; @@ -9173,11 +9174,11 @@ int RGWRados::check_disk_state(const DoutPrefixProvider *dpp, list_state.pending_map.clear(); // we don't need this and it inflates size if (!list_state.is_delete_marker() && !astate->exists) { - ldout_bitx(bitx, cct, 10) << "INFO: " << __func__ << ": disk state exists" << dendl_bitx; + ldout_bitx(bitx, dpp, 10) << "INFO: " << __func__ << ": disk state exists" << dendl_bitx; /* object doesn't exist right now -- hopefully because it's * marked as !exists and got deleted */ if (list_state.exists) { - ldout_bitx(bitx, cct, 10) << "INFO: " << __func__ << ": index list state exists" << dendl_bitx; + ldout_bitx(bitx, dpp, 10) << "INFO: " << __func__ << ": index list state exists" << dendl_bitx; /* FIXME: what should happen now? Work out if there are any * non-bad ways this could happen (there probably are, but annoying * to handle!) */ @@ -9186,7 +9187,7 @@ int RGWRados::check_disk_state(const DoutPrefixProvider *dpp, // encode a suggested removal of that key list_state.ver.epoch = io_ctx.get_last_version(); list_state.ver.pool = io_ctx.get_id(); - ldout_bitx(bitx, cct, 10) << "INFO: " << __func__ << ": encoding remove of " << list_state.key << " on suggested_updates" << dendl_bitx; + ldout_bitx(bitx, dpp, 10) << "INFO: " << __func__ << ": encoding remove of " << list_state.key << " on suggested_updates" << dendl_bitx; cls_rgw_encode_suggestion(CEPH_RGW_REMOVE | suggest_flag, list_state, suggested_updates); return -ENOENT; } @@ -9223,10 +9224,10 @@ int RGWRados::check_disk_state(const DoutPrefixProvider *dpp, RGWSI_Tier_RADOS::raw_obj_to_obj(manifest->get_obj().bucket, raw_loc, &loc); if (loc.key.ns == RGW_OBJ_NS_MULTIPART) { - ldout_bitx(bitx, cct, 10) << "INFO: " << __func__ << " removing manifest part from index loc=" << loc << dendl_bitx; + ldout_bitx(bitx, dpp, 10) << "INFO: " << __func__ << " removing manifest part from index loc=" << loc << dendl_bitx; r = delete_obj_index(loc, astate->mtime, dpp); if (r < 0) { - ldout_bitx(bitx, cct, 0) << + ldout_bitx(bitx, dpp, 0) << "WARNING: " << __func__ << ": delete_obj_index returned r=" << r << dendl_bitx; } } @@ -9267,11 +9268,11 @@ int RGWRados::check_disk_state(const DoutPrefixProvider *dpp, list_state.exists = true; - ldout_bitx(bitx, cct, 10) << "INFO: " << __func__ << + ldout_bitx(bitx, dpp, 10) << "INFO: " << __func__ << ": encoding update of " << list_state.key << " on suggested_updates" << dendl_bitx; cls_rgw_encode_suggestion(CEPH_RGW_UPDATE | suggest_flag, list_state, suggested_updates); - ldout_bitx(bitx, cct, 10) << "EXITING " << __func__ << dendl_bitx; + ldout_bitx(bitx, dpp, 10) << "EXITING " << __func__ << dendl_bitx; return 0; } // RGWRados::check_disk_state -- 2.39.5