[MDS] add event log

This commit is contained in:
fengdeyiji
2024-07-01 14:56:23 +00:00
committed by ob-robot
parent 84751044cd
commit a0e647499e
8 changed files with 71 additions and 36 deletions

View File

@ -254,11 +254,11 @@ struct ObMdsEventBuffer {
void destroy() {
mds_event_cache_.~ObVtableEventRecycleBuffer();
}
void append(const MdsEventKey &key, const MdsEvent &event, const char *file, const uint32_t line, const char *func) {
void append(const MdsEventKey &key, const MdsEvent &event, const storage::mds::MdsTableBase *mds_table, const char *file, const uint32_t line, const char *func) {
if (OB_NOT_NULL(file) && OB_UNLIKELY(line != 0) && OB_NOT_NULL(func) && OB_NOT_NULL(event.event_)) {
// share::ObTaskController::get().allow_next_syslog();
// ::oceanbase::common::OB_PRINT("[MDS.EVENT]", OB_LOG_LEVEL_INFO, file, line, func, OB_LOG_LOCATION_HASH_VAL, OB_SUCCESS,
// event.event_, LOG_KVS(K(key), K(event)));
share::ObTaskController::get().allow_next_syslog();
::oceanbase::common::OB_PRINT("[MDS.EVENT]", OB_LOG_LEVEL_INFO, file, line, func, OB_LOG_LOCATION_HASH_VAL, OB_SUCCESS,
event.event_, LOG_KVS(K(key), K(event), KPC(mds_table)));
}
if (is_inited_) {
(void) mds_event_cache_.append(key, event, file, line, func);
@ -295,8 +295,13 @@ struct ObMdsEventBuffer {
};
static int init() { return Singleton::get_instance().init(); }
static void destroy() { return Singleton::get_instance().destroy(); }
static void append(const MdsEventKey &key, const MdsEvent &event, const char *file, const uint32_t line, const char *func) {
return Singleton::get_instance().append(key, event, file, line, func);
static void append(const MdsEventKey &key,
const MdsEvent &event,
const storage::mds::MdsTableBase *mds_table,
const char *file,
const uint32_t line,
const char *func) {
return Singleton::get_instance().append(key, event, mds_table, file, line, func);
}
template <typename OP>
static int for_each(const MdsEventKey &key, OP &&op) {

View File

@ -349,7 +349,7 @@ void UserMdsNode<K, V>::report_event_(const char (&event_str)[N],
observer::MdsEventKey key(MTL_ID(),
p_mds_row_->p_mds_unit_->p_mds_table_->ls_id_,
p_mds_row_->p_mds_unit_->p_mds_table_->tablet_id_);
observer::ObMdsEventBuffer::append(key, event, file, line, function_name);
observer::ObMdsEventBuffer::append(key, event, p_mds_row_->p_mds_unit_->p_mds_table_, file, line, function_name);
}
}

View File

@ -229,13 +229,15 @@ int MdsRow<K, V>::construct_insert_record_user_mds_node_(MdsRowBase<K, V> *mds_r
MDS_TG(5_ms);
bool need_rollback_node = false;
UserMdsNode<K, V> *new_node = nullptr;
if (GET_MIN_CLUSTER_VERSION() >= CLUSTER_VERSION_4_3_0_0 && !scn.is_max()) {// write operation on leader after upgrade
if (!ctx.get_seq_no().is_valid()) {
if (GET_MIN_CLUSTER_VERSION() >= CLUSTER_VERSION_4_3_0_0) {
if (!scn.is_max() && !ctx.get_seq_no().is_valid()) {
ctx.set_seq_no(transaction::ObTxSEQ::MIN_VAL());
MDS_LOG_SET(WARN, "seq no on mds ctx is invalid, maybe meet old version CLOG, convert to min scn");
}
if (OB_FAIL(sorted_list_.reverse_for_each_node(CheckNodeInSameWriterSeqIncLogicOp(ctx)))) {// can not assert here, cause some modules maynot adapt this logic yet
MDS_LOG_SET(WARN, "seq_no is not satisfied inc logic");
if (scn.is_max()) {// write operation on leader after upgrade
if (OB_FAIL(sorted_list_.reverse_for_each_node(CheckNodeInSameWriterSeqIncLogicOp(ctx)))) {// can not assert here, cause some modules maynot adapt this logic yet
MDS_LOG_SET(WARN, "seq_no is not satisfied inc logic");
}
}
}
#ifndef UNITTEST_DEBUG
@ -793,7 +795,7 @@ void MdsRow<K, V>::report_event_(const char (&event_str)[N],
observer::MdsEventKey key(MTL_ID(),
MdsRowBase<K, V>::p_mds_unit_->p_mds_table_->ls_id_,
MdsRowBase<K, V>::p_mds_unit_->p_mds_table_->tablet_id_);
observer::ObMdsEventBuffer::append(key, event, file, line, function_name);
observer::ObMdsEventBuffer::append(key, event, MdsRowBase<K, V>::p_mds_unit_->p_mds_table_, file, line, function_name);
}
}

View File

@ -72,7 +72,6 @@ int MdsTableBase::init(const ObTabletID tablet_id,
MDS_LOG(WARN, "fail to register mds table", KR(ret), K(*this), K(ls_id), K(tablet_id));
}
}
MDS_LOG(INFO, "mds table inited", KR(ret), K(*this));
}
return ret;
}
@ -86,6 +85,8 @@ int MdsTableBase::register_to_mds_table_mgr()
MDS_LOG(WARN, "mds_table_mgr ptr is null", KR(ret), K(*this));
} else if (MDS_FAIL(mgr_handle_.get_mds_table_mgr()->register_to_mds_table_mgr(this))) {
MDS_LOG(WARN, "fail to register mds table", KR(ret), K(*this));
} else {
report_construct_event_();
}
return ret;
}
@ -139,6 +140,8 @@ int MdsTableBase::unregister_from_mds_table_mgr()
MDS_LOG(INFO, "no need unregister from mds_table_mgr cause invalid id", KR(ret), K(*this));
} else if (MDS_FAIL(mgr_handle_.get_mds_table_mgr()->unregister_from_mds_table_mgr(this))) {
MDS_LOG(ERROR, "fail to unregister mds table", K(*this));
} else {
report_destruct_event_();
}
return ret;
}

View File

@ -194,6 +194,32 @@ protected:
int unregister_from_mds_table_mgr();// call when marked deleted or released directly
int unregister_from_removed_recorder();// call when marked deleted
int merge(const int64_t construct_sequence, const share::SCN &flushing_scn);
void report_construct_event_(const char *file = __builtin_FILE(),
const uint32_t line = __builtin_LINE(),
const char *function_name = __builtin_FUNCTION()) {
int ret = OB_SUCCESS;
observer::MdsEvent event;
event.record_thread_info_();
event.info_str_.reset();
event.event_ = "CONSTRUCTED";
observer::MdsEventKey key(MTL_ID(),
ls_id_,
tablet_id_);
observer::ObMdsEventBuffer::append(key, event, this, file, line, function_name);
}
void report_destruct_event_(const char *file = __builtin_FILE(),
const uint32_t line = __builtin_LINE(),
const char *function_name = __builtin_FUNCTION()) {
int ret = OB_SUCCESS;
observer::MdsEvent event;
event.record_thread_info_();
event.info_str_.reset();
event.event_ = "DESTRUCTED";
observer::MdsEventKey key(MTL_ID(),
ls_id_,
tablet_id_);
observer::ObMdsEventBuffer::append(key, event, this, file, line, function_name);
}
template <int N>
void report_rec_scn_event_(const char (&event_str)[N],
share::SCN old_scn,
@ -214,7 +240,7 @@ protected:
observer::MdsEventKey key(MTL_ID(),
ls_id_,
tablet_id_);
observer::ObMdsEventBuffer::append(key, event, file, line, function_name);
observer::ObMdsEventBuffer::append(key, event, this, file, line, function_name);
}
}
template <int N>
@ -237,7 +263,7 @@ protected:
observer::MdsEventKey key(MTL_ID(),
ls_id_,
tablet_id_);
observer::ObMdsEventBuffer::append(key, event, file, line, function_name);
observer::ObMdsEventBuffer::append(key, event, this, file, line, function_name);
}
REPORT_CHECKPOINT_DIAGNOSE_INFO(update_schedule_dag_info, this, rec_scn_, rec_scn_, flushing_scn_);
@ -263,7 +289,7 @@ protected:
observer::MdsEventKey key(MTL_ID(),
ls_id_,
tablet_id_);
observer::ObMdsEventBuffer::append(key, event, file, line, function_name);
observer::ObMdsEventBuffer::append(key, event, this, file, line, function_name);
}
REPORT_CHECKPOINT_DIAGNOSE_INFO(update_merge_info_for_checkpoint_unit, this);
@ -285,7 +311,7 @@ protected:
observer::MdsEventKey key(MTL_ID(),
ls_id_,
tablet_id_);
observer::ObMdsEventBuffer::append(key, event, file, line, function_name);
observer::ObMdsEventBuffer::append(key, event, this, file, line, function_name);
}
}
protected:

View File

@ -77,7 +77,6 @@ MdsTableImpl<MdsTableType>::~MdsTableImpl() {
if (OB_FAIL(unregister_from_removed_recorder())) {
MDS_LOG(ERROR, "fail to unregister from removed_recorder", K(*this));
}
MDS_LOG(INFO, "mds table destructed", K(*this));
}
template <typename MdsTableImpl>

View File

@ -203,8 +203,8 @@ int MdsUnit<K, V>::for_each_row(FowEachRowAction action_type, OP &&op)// node ma
// but destroy mds_row will add row's lock inner destruction, which will resulting deadlock in same thread.
// so only operations logic behaves like gc should recycle empty row.
if (FowEachRowAction::RECYCLE == action_type || FowEachRowAction::RESET == action_type) {
erase_kv_from_list_if_empty_(&const_cast<KvPair<K, Row<K, V>> &>(kv_row));
MDS_LOG_SCAN(DEBUG, "scan row to recycle or reset", K(action_type), KPC(p_k));
erase_kv_from_list_if_empty_(&const_cast<KvPair<K, Row<K, V>> &>(kv_row));
}
return OB_SUCCESS != ret;// keep scanning until meet failure
});
@ -597,7 +597,7 @@ void MdsUnit<K, V>::report_event_(const char (&event_str)[N],
observer::MdsEventKey key(MTL_ID(),
MdsUnitBase<K, V>::p_mds_table_->ls_id_,
MdsUnitBase<K, V>::p_mds_table_->tablet_id_);
observer::ObMdsEventBuffer::append(key, event, file, line, function_name);
observer::ObMdsEventBuffer::append(key, event, MdsUnitBase<K, V>::p_mds_table_, file, line, function_name);
}
}

View File

@ -79,15 +79,15 @@ int ObMdsTableMergeTask::process()
bool need_schedule_mds_minor = true;
if (OB_UNLIKELY(!is_inited_)) {
ret = OB_NOT_INIT;
LOG_WARN("not inited", K(ret), K_(is_inited));
LOG_WARN("not inited", K(ret), K_(is_inited), KPC(mds_merge_dag_));
} else if (OB_ISNULL(mds_merge_dag_)) {
ret = OB_ERR_UNEXPECTED;
LOG_WARN("get unexpected null dag", K(ret));
LOG_WARN("get unexpected null dag", K(ret), KPC(mds_merge_dag_));
} else if (OB_FAIL(mds_merge_dag_->alloc_merge_ctx())) {
LOG_WARN("failed to prepare merge ctx", K(ret), KPC_(mds_merge_dag));
LOG_WARN("failed to prepare merge ctx", K(ret), KPC_(mds_merge_dag), KPC(mds_merge_dag_));
} else if (OB_ISNULL(ctx_ptr = static_cast<ObTabletMergeCtx *>(mds_merge_dag_->get_ctx()))) {
ret = OB_ERR_UNEXPECTED;
LOG_WARN("ctx is unexpected null", KR(ret), KPC_(mds_merge_dag));
LOG_WARN("ctx is unexpected null", KR(ret), KPC_(mds_merge_dag), KPC(mds_merge_dag_));
} else {
int tmp_ret = OB_SUCCESS;
ObLS *ls = nullptr;
@ -109,28 +109,28 @@ int ObMdsTableMergeTask::process()
const int64_t mds_construct_sequence = mds_merge_dag_->get_mds_construct_sequence();
ObTableHandleV2 table_handle;
if (OB_FAIL(ctx.get_ls_and_tablet())) {
LOG_WARN("failed to get ls and tablet", KR(ret), K(ctx));
LOG_WARN("failed to get ls and tablet", KR(ret), K(ctx), KPC(mds_merge_dag_));
} else if (OB_ISNULL(ls = ctx.get_ls())) {
ret = OB_ERR_UNEXPECTED;
LOG_WARN("ls is null", K(ret), K(ls_id), "ls_handle", ctx.static_param_.ls_handle_);
LOG_WARN("ls is null", K(ret), K(ls_id), "ls_handle", ctx.static_param_.ls_handle_, KPC(mds_merge_dag_));
} else if (ls->is_offline()) {
ret = OB_CANCELED;
LOG_INFO("ls offline, skip merge", K(ret), K(ctx));
LOG_INFO("ls offline, skip merge", K(ret), K(ctx), KPC(mds_merge_dag_));
} else if (OB_FAIL(ctx.init_tablet_merge_info(false/*need_check*/))) {
LOG_WARN("failed to init tablet merge info", K(ret), K(ls_id), K(tablet_id));
LOG_WARN("failed to init tablet merge info", K(ret), K(ls_id), K(tablet_id), KPC(mds_merge_dag_));
} else if (ctx.get_tablet()->get_mds_checkpoint_scn() >= flush_scn) {
tablet = ctx.get_tablet();
need_schedule_mds_minor = false;
FLOG_INFO("flush scn smaller than mds ckpt scn, only flush nodes of mds table and do not generate mds mini",
K(ls_id), K(tablet_id), K(flush_scn),
"mds_checkpoint_scn", ctx.get_tablet()->get_mds_checkpoint_scn());
"mds_checkpoint_scn", ctx.get_tablet()->get_mds_checkpoint_scn(), KPC(mds_merge_dag_));
ctx.time_guard_click(ObStorageCompactionTimeGuard::EXECUTE);
share::dag_yield();
} else if (FALSE_IT(ctx.static_param_.scn_range_.start_scn_ = ctx.get_tablet()->get_mds_checkpoint_scn())) {
} else if (MDS_FAIL(build_mds_sstable(ctx, mds_construct_sequence, table_handle))) {
LOG_WARN("fail to build mds sstable", K(ret), K(ls_id), K(tablet_id));
LOG_WARN("fail to build mds sstable", K(ret), K(ls_id), K(tablet_id), KPC(mds_merge_dag_));
} else if (MDS_FAIL(ls->build_new_tablet_from_mds_table(ctx, ctx.get_ls_rebuild_seq(), tablet_id, table_handle, flush_scn, new_tablet_handle))) {
LOG_WARN("failed to build new tablet from mds table", K(ret), K(ctx), K(ls_id), K(tablet_id), K(ctx.get_ls_rebuild_seq()), K(flush_scn));
LOG_WARN("failed to build new tablet from mds table", K(ret), K(ctx), K(ls_id), K(tablet_id), K(ctx.get_ls_rebuild_seq()), K(flush_scn), KPC(mds_merge_dag_));
} else {
tablet = ctx.get_tablet();
ctx.time_guard_click(ObStorageCompactionTimeGuard::EXECUTE);
@ -139,7 +139,7 @@ int ObMdsTableMergeTask::process()
// always notify flush ret
if (OB_NOT_NULL(tablet) && MDS_TMP_FAIL(tablet->notify_mds_table_flush_ret(flush_scn, ret))) {
LOG_WARN("failed to notify mds table flush ret", K(tmp_ret), K(ls_id), K(tablet_id), K(flush_scn), "flush_ret", ret);
LOG_WARN("failed to notify mds table flush ret", K(tmp_ret), K(ls_id), K(tablet_id), K(flush_scn), "flush_ret", ret, KPC(mds_merge_dag_));
if (OB_SUCC(ret)) {
// ret equals to OB_SUCCESS, use tmp_ret as return value
ret = tmp_ret;
@ -153,7 +153,7 @@ int ObMdsTableMergeTask::process()
}
// ATTENTION! Critical diagnostic log, DO NOT CHANGE!!!
FLOG_INFO("sstable merge finish", K(ret), "merge_info", ctx_ptr->get_merge_info(),
"time_guard", ctx_ptr->info_collector_.time_guard_);
"time_guard", ctx_ptr->info_collector_.time_guard_, KPC(mds_merge_dag_));
// try schedule mds minor after mds mini
if (OB_SUCC(ret) && need_schedule_mds_minor) {
@ -171,7 +171,7 @@ void ObMdsTableMergeTask::try_schedule_compaction_after_mds_mini(compaction::ObT
const common::ObTabletID &tablet_id = ctx.get_tablet_id();
if (OB_UNLIKELY(!ls_id.is_valid() || !tablet_id.is_valid() || !tablet_handle.is_valid())) {
ret = OB_INVALID_ARGUMENT;
LOG_WARN("invalid args", K(ret), K(ls_id), K(tablet_id), K(tablet_handle));
LOG_WARN("invalid args", K(ret), K(ls_id), K(tablet_id), K(tablet_handle), KPC(mds_merge_dag_));
// when restoring, some log stream may be not ready,
// thus the inner sql in ObTenantFreezeInfoMgr::try_update_info may timeout
} else if (!MTL(ObTenantTabletScheduler *)->is_restore()) {
@ -181,10 +181,10 @@ void ObMdsTableMergeTask::try_schedule_compaction_after_mds_mini(compaction::ObT
compaction::MDS_MINOR_MERGE, ctx.static_param_.ls_handle_, tablet_handle))) {
if (OB_SIZE_OVERFLOW != ret) {
LOG_WARN("failed to schedule special tablet minor merge which triggle mds",
K(ret), K(ls_id), K(tablet_id));
K(ret), K(ls_id), K(tablet_id), KPC(mds_merge_dag_));
}
} else {
LOG_INFO("succeed to try schedule mds minor after mds", K(ls_id), K(tablet_id));
LOG_INFO("succeed to try schedule mds minor after mds", K(ls_id), K(tablet_id), KPC(mds_merge_dag_));
}
}
}