hcq/oceanbase
hcq/oceanbase
1
0
Fork 0
Code Issues Pull Requests Actions 1 Packages Projects Releases Wiki Activity

[ENHANCE] add debug info on mvcc row

Browse Source
This commit is contained in:
Handora 2024-12-17 02:45:07 +00:00 committed by ob-robot
parent 1777b2dc8d
commit 8fa0c1de8c
5 changed files with 126 additions and 10 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

11
src/storage/memtable/mvcc/ob_mvcc_define.h
View File

@ -187,6 +187,17 @@ public:
}
};
// used only for debug during mvcc_write
struct ObMvccWriteDebugInfo {
ObMvccWriteDebugInfo()
: memtable_iterate_cnt_(0),
sstable_iterate_cnt_(0) {}
int64_t memtable_iterate_cnt_;
int64_t sstable_iterate_cnt_;
// TODO(handora.qc): add more debug info if necessary
// int64_t exist_table_bitmap_;
};
} // namespace memtable
} // namespace oceanbase

18
src/storage/memtable/mvcc/ob_mvcc_row.cpp
View File

@ -285,6 +285,11 @@ void ObMvccRow::reset()
last_compact_cnt_ = 0;
max_modify_scn_.set_invalid();
min_modify_scn_.set_invalid();
#ifdef ENABLE_DEBUG_LOG
lower_lock_scanned_ts_ = 0;
lower_lock_scanned_info_.raw_value_ = 0;
#endif
}
int64_t ObMvccRow::to_string(char *buf, const int64_t buf_len) const
@ -323,6 +328,19 @@ int64_t ObMvccRow::to_string(char *buf, const int64_t buf_len) const
common::databuff_printf(buf, buf_len, pos, max_modify_scn_);
common::databuff_printf(buf, buf_len, pos, " min_modify_scn=");
common::databuff_printf(buf, buf_len, pos, min_modify_scn_);
#ifdef ENABLE_DEBUG_LOG
common::databuff_printf(buf, buf_len, pos,
" lower_lock_ts=%ld "
"lower_lock_mem_cnt=%hd "
"lower_lock_sst_cnt=%hd "
"lower_lock_tx_id=%d",
lower_lock_scanned_ts_,
lower_lock_scanned_info_.lower_lock_scanned_memtable_cnt_,
lower_lock_scanned_info_.lower_lock_scanned_sstable_cnt_,
lower_lock_scanned_info_.lower_lock_scanned_tx_id_);
#endif
common::databuff_printf(buf, buf_len, pos, "}");
return pos;
}

46
src/storage/memtable/mvcc/ob_mvcc_row.h
View File

@ -280,9 +280,27 @@ struct ObMvccRow
ObMvccTransNode *latest_compact_node_;
ObMvccRowIndex *index_;
// for row lock 4377 problem debug
#ifdef ENABLE_DEBUG_LOG
int64_t lower_lock_scanned_ts_;
union {
int64_t raw_value_;
struct {
int32_t lower_lock_scanned_tx_id_ : 32;
int16_t lower_lock_scanned_memtable_cnt_ : 16;
int16_t lower_lock_scanned_sstable_cnt_ : 16;
};
} lower_lock_scanned_info_;
#endif
ObMvccRow()
{
#ifdef ENABLE_DEBUG_LOG
STATIC_ASSERT(sizeof(ObMvccRow) <= 136, "Size of ObMvccRow Overflow.");
#else
STATIC_ASSERT(sizeof(ObMvccRow) <= 120, "Size of ObMvccRow Overflow.");
#endif
reset();
}
void reset();
@ -406,9 +424,35 @@ struct ObMvccRow
{
return ATOMIC_LOAD(&flag_) & F_LOWER_LOCK_SCANED;
}
OB_INLINE void set_lower_lock_scaned()
OB_INLINE void set_lower_lock_scaned(const transaction::ObTransID &lower_lock_tx_id,
const int64_t lower_lock_mem_cnt,
const int64_t lower_lock_sst_cnt)
{
#ifdef ENABLE_DEBUG_LOG
while (true) {
const uint8_t old = ATOMIC_LOAD(&(flag_));
if (old & F_LOWER_LOCK_SCANED) {
break;
} else {
const uint8_t tmp = (old | (F_LOWER_LOCK_SCANED));
if (ATOMIC_BCAS(&(flag_), old, tmp)) {
lower_lock_scanned_ts_ = ObTimeUtility::current_time();
lower_lock_scanned_info_.lower_lock_scanned_tx_id_ =
static_cast<int32_t>(lower_lock_tx_id.get_id());
lower_lock_scanned_info_.lower_lock_scanned_memtable_cnt_ =
static_cast<int16_t>(lower_lock_mem_cnt);
lower_lock_scanned_info_.lower_lock_scanned_sstable_cnt_ =
static_cast<int16_t>(lower_lock_sst_cnt);
break;
}
}
}
#else
UNUSED(lower_lock_tx_id);
UNUSED(lower_lock_mem_cnt);
UNUSED(lower_lock_sst_cnt);
ATOMIC_ADD_TAG(F_LOWER_LOCK_SCANED);
#endif
}
// ===================== ObMvccRow Helper Function =====================
int64_t to_string(char *buf, const int64_t buf_len) const;

58
src/storage/memtable/ob_memtable.cpp
View File

@ -1321,15 +1321,27 @@ int ObMemtable::lock_row_on_frozen_stores_(
} else {
ObRowState row_state;
common::ObSEArray<ObITable *, 4> iter_tables;
ObMvccWriteDebugInfo debug_info;
if (OB_FAIL(get_all_tables_(ctx, iter_tables))) {
TRANS_LOG(WARN, "get all tables from table iter failed", KR(ret));
} else if (OB_FAIL(internal_lock_row_on_frozen_stores_(
check_exist, key, param, iter_tables, context, res, row_state))) {
} else if (OB_FAIL(internal_lock_row_on_frozen_stores_(check_exist,
key,
param,
iter_tables,
context,
debug_info,
res,
row_state))) {
TRANS_LOG(WARN, "internal lock row failed", KR(ret));
} else {
lock_state.trans_version_ = MAX(lock_state.trans_version_, row_state.get_max_trans_version());
if (OB_FAIL(lock_row_on_frozen_stores_on_success(lock_state.is_locked_, arg.data_->dml_flag_,
lock_state.trans_version_, context, value, res))) {
if (OB_FAIL(lock_row_on_frozen_stores_on_success(lock_state.is_locked_,
arg.data_->dml_flag_,
lock_state.trans_version_,
context,
debug_info,
value,
res))) {
if (OB_UNLIKELY(OB_TRANSACTION_SET_VIOLATION != ret)) {
TRANS_LOG(WARN, "Failed to call on success callback after lock row on frozen stores", K(ret));
}
@ -1367,6 +1379,7 @@ int ObMemtable::internal_lock_row_on_frozen_stores_(const bool check_exist,
const storage::ObTableIterParam &param,
const ObIArray<ObITable *> &iter_tables,
storage::ObTableAccessContext &context,
ObMvccWriteDebugInfo &debug_info,
ObMvccWriteResult &res,
ObRowState &row_state)
@ -1394,6 +1407,8 @@ int ObMemtable::internal_lock_row_on_frozen_stores_(const bool check_exist,
// FIXME(handora.qc): two active memtable in transfer
if (OB_FAIL(mvcc_engine.check_row_locked(ctx.mvcc_acc_ctx_, key, tmp_lock_state, row_state))) {
TRANS_LOG(WARN, "mvcc engine check row lock fail", K(ret), K(lock_state), K(tmp_lock_state));
} else {
debug_info.memtable_iterate_cnt_++;
}
} else if (iter_tables.at(i)->is_sstable()) {
blocksstable::ObDatumRowkeyHelper rowkey_converter;
@ -1412,6 +1427,8 @@ int ObMemtable::internal_lock_row_on_frozen_stores_(const bool check_exist,
K(lock_state),
K(tmp_lock_state),
K(row_state));
} else {
debug_info.sstable_iterate_cnt_++;
}
TRANS_LOG(DEBUG,
"sstable check row lock debug",
@ -1440,6 +1457,8 @@ int ObMemtable::internal_lock_row_on_frozen_stores_(const bool check_exist,
K(lock_state),
K(tmp_lock_state),
K(row_state));
} else {
debug_info.sstable_iterate_cnt_++;
}
TRANS_LOG(DEBUG,
"direct load memtable check row lock debug",
@ -1489,6 +1508,7 @@ int ObMemtable::lock_row_on_frozen_stores_on_success(
const blocksstable::ObDmlFlag writer_dml_flag,
const share::SCN &max_trans_version,
storage::ObTableAccessContext &context,
ObMvccWriteDebugInfo &debug_info,
ObMvccRow *value,
ObMvccWriteResult &res)
{
@ -1507,7 +1527,9 @@ int ObMemtable::lock_row_on_frozen_stores_on_success(
ret = OB_TRANSACTION_SET_VIOLATION;
TRANS_LOG(WARN, "TRANS_SET_VIOLATION", K(ret), K(max_trans_version), "ctx", ctx);
}
value->set_lower_lock_scaned();
value->set_lower_lock_scaned(my_tx_id,
debug_info.memtable_iterate_cnt_,
debug_info.sstable_iterate_cnt_);
TRANS_LOG(DEBUG, "lower lock check finish", K(*value));
} else {
// There is the lock on frozen stores by my self
@ -1616,12 +1638,18 @@ int ObMemtable::lock_rows_on_frozen_stores_(
// so there is no need to check transaction conflict again.
} else {
common::ObSEArray<ObITable *, 4> iter_tables;
ObMvccWriteDebugInfo debug_info;
if (OB_FAIL(get_all_tables_(ctx, iter_tables))) {
TRANS_LOG(WARN, "get all tables from table iter failed", KR(ret));
} else {
share::SCN max_trans_version = SCN::min_scn();
if (OB_FAIL(internal_lock_rows_on_frozen_stores_(check_exist, iter_tables, param, context,
max_trans_version, rows_info))) {
if (OB_FAIL(internal_lock_rows_on_frozen_stores_(check_exist,
iter_tables,
param,
context,
debug_info,
max_trans_version,
rows_info))) {
TRANS_LOG(WARN, "Failed to lock rows on frozen stores", K(ret), K(check_exist), K(iter_tables));
} else if (!rows_info.have_conflict()) {
for (int64_t i = 0; OB_SUCC(ret) && i < mvcc_rows.count(); ++i) {
@ -1634,8 +1662,11 @@ int ObMemtable::lock_rows_on_frozen_stores_(
row_lock_state.trans_version_ = MAX(row_lock_state.trans_version_, max_trans_version);
if (OB_FAIL(lock_row_on_frozen_stores_on_success(row_lock_state.is_locked_,
blocksstable::ObDmlFlag::DF_INSERT,
row_lock_state.trans_version_, context,
mvcc_row, write_result))) {
row_lock_state.trans_version_,
context,
debug_info,
mvcc_row,
write_result))) {
TRANS_LOG(WARN, "Failed to lock rows on frozen stores", K(ret), K(check_exist), K(iter_tables));
// The upper layer determines whether to call lock_row_on_frozen_stores_on_failure based on whether rows_info has a conflict.
// Therefore, here we convert the error code to success and store the error code in rows_info.
@ -1657,6 +1688,7 @@ int ObMemtable::internal_lock_rows_on_frozen_stores_(
const ObIArray<ObITable *> &iter_tables,
const storage::ObTableIterParam &param,
storage::ObTableAccessContext &context,
ObMvccWriteDebugInfo &debug_info,
share::SCN &max_trans_version,
ObRowsInfo &rows_info)
{
@ -1668,6 +1700,8 @@ int ObMemtable::internal_lock_rows_on_frozen_stores_(
if (OB_FAIL(memtable->check_rows_locked(check_exist, param, context, rows_info))) {
TRANS_LOG(WARN, "Failed to check rows locked and duplication in memtable", K(ret), K(i),
K(iter_tables));
} else {
debug_info.memtable_iterate_cnt_++;
}
} else if (i_table->is_sstable()) {
ObSSTable *sstable = static_cast<ObSSTable *>(i_table);
@ -1678,6 +1712,8 @@ int ObMemtable::internal_lock_rows_on_frozen_stores_(
context,
rows_info))) {
TRANS_LOG(WARN, "Failed to check rows locked for sstable", K(ret), K(i), K(iter_tables));
} else {
debug_info.sstable_iterate_cnt_++;
}
} else {
if (OB_FAIL(sstable->check_rows_locked(check_exist,
@ -1685,6 +1721,8 @@ int ObMemtable::internal_lock_rows_on_frozen_stores_(
max_trans_version,
rows_info))) {
TRANS_LOG(WARN, "Failed to check rows locked for sstable", K(ret), K(i), K(iter_tables));
} else {
debug_info.sstable_iterate_cnt_++;
}
}
} else if (i_table->is_direct_load_memtable()) {
@ -1696,6 +1734,8 @@ int ObMemtable::internal_lock_rows_on_frozen_stores_(
} else {
ret = OB_SUCCESS;
}
} else {
debug_info.sstable_iterate_cnt_++;
}
} else {
ret = OB_ERR_UNEXPECTED;

3
src/storage/memtable/ob_memtable.h
View File

@ -501,6 +501,7 @@ private:
const blocksstable::ObDmlFlag writer_dml_flag,
const share::SCN &max_trans_version,
storage::ObTableAccessContext &context,
ObMvccWriteDebugInfo &debug_info,
ObMvccRow *value,
ObMvccWriteResult &res);
@ -524,6 +525,7 @@ private:
const storage::ObTableIterParam &param,
const ObIArray<ObITable *> &iter_tables,
storage::ObTableAccessContext &context,
ObMvccWriteDebugInfo &debug_info,
ObMvccWriteResult &res,
ObRowState &row_state);
@ -532,6 +534,7 @@ private:
const ObIArray<ObITable *> &iter_tables,
const storage::ObTableIterParam &param,
storage::ObTableAccessContext &context,
ObMvccWriteDebugInfo &debug_info,
share::SCN &max_trans_version,
ObRowsInfo &rows_info);