This is an automated email from the ASF dual-hosted git repository.
dataroaring pushed a commit to branch branch-3.0
in repository https://gitbox.apache.org/repos/asf/doris.git
The following commit(s) were added to refs/heads/branch-3.0 by this push:
new ee46be6a6a9 branch-3.0: [improve](cloud-mow) modify some log (#47347)
(#47433)
ee46be6a6a9 is described below
commit ee46be6a6a944b835887d14bc33dfc2c85dd237c
Author: meiyi <[email protected]>
AuthorDate: Sun Jan 26 09:03:24 2025 +0800
branch-3.0: [improve](cloud-mow) modify some log (#47347) (#47433)
pick https://github.com/apache/doris/pull/47347
---
be/src/cloud/cloud_tablet.cpp | 17 ++++++++++++++---
cloud/src/meta-service/meta_service.cpp | 21 +++++++++++++--------
cloud/src/meta-service/meta_service_helper.h | 11 +++++++++--
cloud/src/meta-service/meta_service_job.cpp | 16 ++++++++++------
cloud/src/meta-service/meta_service_txn.cpp | 8 +++++---
cloud/test/meta_service_job_test.cpp | 2 +-
.../transaction/CloudGlobalTransactionMgr.java | 11 +++++------
7 files changed, 57 insertions(+), 29 deletions(-)
diff --git a/be/src/cloud/cloud_tablet.cpp b/be/src/cloud/cloud_tablet.cpp
index e3c01365bb1..1642fd9efd5 100644
--- a/be/src/cloud/cloud_tablet.cpp
+++ b/be/src/cloud/cloud_tablet.cpp
@@ -855,16 +855,21 @@ Status CloudTablet::calc_delete_bitmap_for_compaction(
}
// 2. calc delete bitmap for incremental data
+ int64_t t1 = MonotonicMicros();
RETURN_IF_ERROR(_engine.meta_mgr().get_delete_bitmap_update_lock(
*this, COMPACTION_DELETE_BITMAP_LOCK_ID, initiator));
+ int64_t t2 = MonotonicMicros();
RETURN_IF_ERROR(_engine.meta_mgr().sync_tablet_rowsets(this));
+ int64_t t3 = MonotonicMicros();
calc_compaction_output_rowset_delete_bitmap(
input_rowsets, rowid_conversion, version.second, UINT64_MAX,
missed_rows.get(),
location_map.get(), tablet_meta()->delete_bitmap(),
output_rowset_delete_bitmap.get());
+ int64_t t4 = MonotonicMicros();
if (location_map) {
RETURN_IF_ERROR(check_rowid_conversion(output_rowset, *location_map));
}
+ int64_t t5 = MonotonicMicros();
if (missed_rows) {
DCHECK_EQ(missed_rows->size(), missed_rows_size);
if (missed_rows->size() != missed_rows_size) {
@@ -874,9 +879,15 @@ Status CloudTablet::calc_delete_bitmap_for_compaction(
}
// 3. store delete bitmap
- RETURN_IF_ERROR(_engine.meta_mgr().update_delete_bitmap(*this, -1,
initiator,
-
output_rowset_delete_bitmap.get()));
- return Status::OK();
+ auto st = _engine.meta_mgr().update_delete_bitmap(*this, -1, initiator,
+
output_rowset_delete_bitmap.get());
+ int64_t t6 = MonotonicMicros();
+ LOG(INFO) << "calc_delete_bitmap_for_compaction, tablet_id=" << tablet_id()
+ << ", get lock cost " << (t2 - t1) << " us, sync rowsets cost "
<< (t3 - t2)
+ << " us, calc delete bitmap cost " << (t4 - t3) << " us, check
rowid conversion cost "
+ << (t5 - t4) << " us, store delete bitmap cost " << (t6 - t5)
+ << " us, st=" << st.to_string();
+ return st;
}
Status CloudTablet::sync_meta() {
diff --git a/cloud/src/meta-service/meta_service.cpp
b/cloud/src/meta-service/meta_service.cpp
index 58e2a6fd4e8..2d73c6d897f 100644
--- a/cloud/src/meta-service/meta_service.cpp
+++ b/cloud/src/meta-service/meta_service.cpp
@@ -1870,7 +1870,8 @@ void
MetaServiceImpl::update_delete_bitmap(google::protobuf::RpcController* cont
txn->put(pending_key, pending_val);
fdb_txn_size = fdb_txn_size + pending_key.size() + pending_val.size();
LOG(INFO) << "xxx update delete bitmap put pending_key=" <<
hex(pending_key)
- << " lock_id=" << request->lock_id() << " value_size: " <<
pending_val.size();
+ << " lock_id=" << request->lock_id() << " initiator=" <<
request->initiator()
+ << " value_size: " << pending_val.size();
} else if (request->lock_id() == -3) {
// delete existing key
for (size_t i = 0; i < request->rowset_ids_size(); ++i) {
@@ -1899,7 +1900,8 @@ void
MetaServiceImpl::update_delete_bitmap(google::protobuf::RpcController* cont
if (txn->approximate_bytes() + key.size() * 3 + val.size() >
config::max_txn_commit_byte) {
LOG(INFO) << "fdb txn size more than " <<
config::max_txn_commit_byte
<< ", current size: " << txn->approximate_bytes()
- << " lock_id=" << request->lock_id() << ", need to
commit";
+ << " lock_id=" << request->lock_id() << " initiator=" <<
request->initiator()
+ << ", need to commit";
err = txn->commit();
total_txn_put_keys += txn->num_put_keys();
total_txn_put_bytes += txn->put_bytes();
@@ -1907,7 +1909,7 @@ void
MetaServiceImpl::update_delete_bitmap(google::protobuf::RpcController* cont
if (err != TxnErrorCode::TXN_OK) {
code = cast_as<ErrCategory::COMMIT>(err);
ss << "failed to update delete bitmap, err=" << err << "
tablet_id=" << tablet_id
- << " lock_id=" << request->lock_id()
+ << " lock_id=" << request->lock_id() << " initiator=" <<
request->initiator()
<< " delete_bitmap_key=" << current_key_count
<< " delete_bitmap_value=" << current_value_count
<< " put_size=" << txn->put_bytes() << " num_put_keys=" <<
txn->num_put_keys()
@@ -1940,8 +1942,8 @@ void
MetaServiceImpl::update_delete_bitmap(google::protobuf::RpcController* cont
total_key_count++;
total_value_count += val.size();
VLOG_DEBUG << "xxx update delete bitmap put delete_bitmap_key=" <<
hex(key)
- << " lock_id=" << request->lock_id() << " key_size: " <<
key.size()
- << " value_size: " << val.size();
+ << " lock_id=" << request->lock_id() << " initiator=" <<
request->initiator()
+ << " key_size: " << key.size() << " value_size: " <<
val.size();
}
err = txn->commit();
total_txn_put_keys += txn->num_put_keys();
@@ -1950,13 +1952,15 @@ void
MetaServiceImpl::update_delete_bitmap(google::protobuf::RpcController* cont
if (err != TxnErrorCode::TXN_OK) {
code = cast_as<ErrCategory::COMMIT>(err);
ss << "failed to update delete bitmap, err=" << err << " tablet_id="
<< tablet_id
- << " lock_id=" << request->lock_id() << " delete_bitmap_key=" <<
current_key_count
+ << " lock_id=" << request->lock_id() << " initiator=" <<
request->initiator()
+ << " delete_bitmap_key=" << current_key_count
<< " delete_bitmap_value=" << current_value_count << " put_size="
<< txn->put_bytes()
<< " num_put_keys=" << txn->num_put_keys() << " txn_size=" <<
txn->approximate_bytes();
msg = ss.str();
return;
}
LOG(INFO) << "update_delete_bitmap tablet_id=" << tablet_id << " lock_id="
<< request->lock_id()
+ << " initiator=" << request->initiator()
<< " rowset_num=" << request->rowset_ids_size()
<< " total_key_count=" << total_key_count
<< " total_value_count=" << total_value_count << " unlock=" <<
unlock
@@ -2230,8 +2234,9 @@ void
MetaServiceImpl::get_delete_bitmap_update_lock(google::protobuf::RpcControl
return;
}
txn->put(lock_key, lock_val);
- LOG(INFO) << "xxx put lock_key=" << hex(lock_key) << " lock_id=" <<
request->lock_id()
- << " initiators_size: " << lock_info.initiators_size();
+ LOG(INFO) << "xxx put lock_key=" << hex(lock_key) << " table_id=" <<
table_id
+ << " lock_id=" << request->lock_id() << " initiator=" <<
request->initiator()
+ << " initiators_size=" << lock_info.initiators_size();
err = txn->commit();
if (err != TxnErrorCode::TXN_OK) {
diff --git a/cloud/src/meta-service/meta_service_helper.h
b/cloud/src/meta-service/meta_service_helper.h
index e4ed7e2a231..7d626dd1186 100644
--- a/cloud/src/meta-service/meta_service_helper.h
+++ b/cloud/src/meta-service/meta_service_helper.h
@@ -60,8 +60,8 @@ void begin_rpc(std::string_view func_name, brpc::Controller*
ctrl, const Request
LOG(INFO) << "begin " << func_name << " from " << ctrl->remote_side();
} else if constexpr (std::is_same_v<Request, UpdateDeleteBitmapRequest>) {
LOG(INFO) << "begin " << func_name << " from " << ctrl->remote_side()
- << " tablet_id=" << req->tablet_id() << " lock_id=" <<
req->lock_id()
- << " initiator=" << req->initiator()
+ << " table_id=" << req->table_id() << " tablet_id=" <<
req->tablet_id()
+ << " lock_id=" << req->lock_id() << " initiator=" <<
req->initiator()
<< " delete_bitmap_size=" <<
req->segment_delete_bitmaps_size();
} else if constexpr (std::is_same_v<Request, GetDeleteBitmapRequest>) {
LOG(INFO) << "begin " << func_name << " from " << ctrl->remote_side()
@@ -77,6 +77,11 @@ void begin_rpc(std::string_view func_name, brpc::Controller*
ctrl, const Request
} else if constexpr (std::is_same_v<Request, RemoveDeleteBitmapRequest>) {
LOG(INFO) << "begin " << func_name << " from " << ctrl->remote_side()
<< " tablet_id=" << req->tablet_id() << " rowset_size=" <<
req->rowset_ids_size();
+ } else if constexpr (std::is_same_v<Request,
GetDeleteBitmapUpdateLockRequest>) {
+ LOG(INFO) << "begin " << func_name << " from " << ctrl->remote_side()
+ << " table_id=" << req->table_id() << " lock_id=" <<
req->lock_id()
+ << " initiator=" << req->initiator() << " expiration=" <<
req->expiration()
+ << " require_compaction_stats=" <<
req->require_compaction_stats();
} else {
LOG(INFO) << "begin " << func_name << " from " << ctrl->remote_side()
<< " request=" << req->ShortDebugString();
@@ -124,6 +129,8 @@ void finish_rpc(std::string_view func_name,
brpc::Controller* ctrl, Response* re
res->clear_cumulative_compaction_cnts();
res->clear_cumulative_points();
}
+ LOG(INFO) << "finish " << func_name << " from " << ctrl->remote_side()
+ << " status=" << res->status().ShortDebugString();
} else if constexpr (std::is_same_v<Response, GetObjStoreInfoResponse> ||
std::is_same_v<Response, GetStageResponse>) {
std::string debug_string = res->DebugString();
diff --git a/cloud/src/meta-service/meta_service_job.cpp
b/cloud/src/meta-service/meta_service_job.cpp
index b7b5e86953d..173c6834b5f 100644
--- a/cloud/src/meta-service/meta_service_job.cpp
+++ b/cloud/src/meta-service/meta_service_job.cpp
@@ -474,7 +474,8 @@ static bool
check_and_remove_delete_bitmap_update_lock(MetaServiceCode& code, st
return false;
}
if (lock_info.lock_id() != lock_id) {
- msg = "lock id not match";
+ ss << "lock id not match, locked by lock_id=" << lock_info.lock_id();
+ msg = ss.str();
code = MetaServiceCode::LOCK_EXPIRED;
return false;
}
@@ -488,13 +489,14 @@ static bool
check_and_remove_delete_bitmap_update_lock(MetaServiceCode& code, st
}
}
if (!found) {
- msg = "lock initiator not exist";
+ ss << "lock initiator " << lock_initiator << " not exist";
+ msg = ss.str();
code = MetaServiceCode::LOCK_EXPIRED;
return false;
}
if (initiators->empty()) {
INSTANCE_LOG(INFO) << "remove delete bitmap lock, table_id=" <<
table_id
- << " key=" << hex(lock_key);
+ << " lock_id=" << lock_id << " key=" <<
hex(lock_key);
txn->remove(lock_key);
return true;
}
@@ -505,7 +507,8 @@ static bool
check_and_remove_delete_bitmap_update_lock(MetaServiceCode& code, st
return false;
}
INSTANCE_LOG(INFO) << "remove delete bitmap lock initiator, table_id=" <<
table_id
- << ", key=" << hex(lock_key) << ", initiator=" <<
lock_initiator
+ << ", key=" << hex(lock_key) << " lock_id=" << lock_id
+ << " initiator=" << lock_initiator
<< " initiators_size=" << lock_info.initiators_size();
txn->put(lock_key, lock_val);
return true;
@@ -547,7 +550,7 @@ static void
remove_delete_bitmap_update_lock(std::unique_ptr<Transaction>& txn,
}
if (initiators->empty()) {
INSTANCE_LOG(INFO) << "remove delete bitmap lock, table_id=" <<
table_id
- << " key=" << hex(lock_key);
+ << " lock_id=" << lock_id << " key=" <<
hex(lock_key);
txn->remove(lock_key);
return;
}
@@ -558,7 +561,8 @@ static void
remove_delete_bitmap_update_lock(std::unique_ptr<Transaction>& txn,
return;
}
INSTANCE_LOG(INFO) << "remove delete bitmap lock initiator, table_id=" <<
table_id
- << ", key=" << hex(lock_key) << ", initiator=" <<
lock_initiator
+ << ", key=" << hex(lock_key) << " lock_id=" << lock_id
+ << " initiator=" << lock_initiator
<< " initiators_size=" << lock_info.initiators_size();
txn->put(lock_key, lock_val);
}
diff --git a/cloud/src/meta-service/meta_service_txn.cpp
b/cloud/src/meta-service/meta_service_txn.cpp
index de64152c69a..b0dbbb40674 100644
--- a/cloud/src/meta-service/meta_service_txn.cpp
+++ b/cloud/src/meta-service/meta_service_txn.cpp
@@ -1206,7 +1206,8 @@ void commit_txn_immediately(
// by another transaction and successfully committed.
if (!lock_values[i].has_value()) {
ss << "get delete bitmap update lock info, lock is expired"
- << " table_id=" << table_id << " key=" << hex(lock_keys[i]);
+ << " table_id=" << table_id << " key=" << hex(lock_keys[i])
+ << " txn_id=" << txn_id;
code = MetaServiceCode::LOCK_EXPIRED;
msg = ss.str();
LOG(WARNING) << msg << " txn_id=" << txn_id;
@@ -1221,13 +1222,14 @@ void commit_txn_immediately(
return;
}
if (lock_info.lock_id() != request->txn_id()) {
- msg = "lock is expired";
+ ss << "lock is expired, locked by lock_id=" <<
lock_info.lock_id();
+ msg = ss.str();
code = MetaServiceCode::LOCK_EXPIRED;
return;
}
txn->remove(lock_keys[i]);
LOG(INFO) << "xxx remove delete bitmap lock, lock_key=" <<
hex(lock_keys[i])
- << " txn_id=" << txn_id;
+ << " table_id=" << table_id << " txn_id=" << txn_id;
for (auto tablet_id : table_id_tablet_ids[table_id]) {
std::string pending_key =
meta_pending_delete_bitmap_key({instance_id, tablet_id});
diff --git a/cloud/test/meta_service_job_test.cpp
b/cloud/test/meta_service_job_test.cpp
index e1dbb0089e2..998a24256f4 100644
--- a/cloud/test/meta_service_job_test.cpp
+++ b/cloud/test/meta_service_job_test.cpp
@@ -1783,7 +1783,7 @@ TEST(MetaServiceJobTest, SchemaChangeJobWithMoWTest) {
finish_schema_change_job(meta_service.get(), tablet_id, new_tablet_id,
"job1", "be1",
output_rowsets, res);
ASSERT_EQ(res.status().code(), MetaServiceCode::LOCK_EXPIRED);
- ASSERT_NE(res.status().msg().find("lock initiator not exist"),
std::string::npos);
+ ASSERT_NE(res.status().msg().find("lock initiator 12345 not exist"),
std::string::npos);
remove_delete_bitmap_lock(meta_service.get(), table_id);
res.Clear();
diff --git
a/fe/fe-core/src/main/java/org/apache/doris/cloud/transaction/CloudGlobalTransactionMgr.java
b/fe/fe-core/src/main/java/org/apache/doris/cloud/transaction/CloudGlobalTransactionMgr.java
index 7bf462cd56c..4596f0e46ee 100644
---
a/fe/fe-core/src/main/java/org/apache/doris/cloud/transaction/CloudGlobalTransactionMgr.java
+++
b/fe/fe-core/src/main/java/org/apache/doris/cloud/transaction/CloudGlobalTransactionMgr.java
@@ -350,7 +350,8 @@ public class CloudGlobalTransactionMgr implements
GlobalTransactionMgrIface {
throws UserException {
List<OlapTable> mowTableList = getMowTableList(tableList,
tabletCommitInfos);
try {
- LOG.info("try to commit transaction, transactionId: {}",
transactionId);
+ LOG.info("try to commit transaction, transactionId: {}, tableIds:
{}", transactionId,
+
tableList.stream().map(Table::getId).collect(Collectors.toList()));
Map<Long, List<TCalcDeleteBitmapPartitionInfo>>
backendToPartitionInfos = null;
if (!mowTableList.isEmpty()) {
DeleteBitmapUpdateLockContext lockContext = new
DeleteBitmapUpdateLockContext();
@@ -900,11 +901,9 @@ public class CloudGlobalTransactionMgr implements
GlobalTransactionMgrIface {
totalRetryTime += retryTime;
}
stopWatch.stop();
- if (totalRetryTime > 0 || stopWatch.getTime() > 20) {
- LOG.info("get delete bitmap lock successfully. txns: {}.
totalRetryTime: {}. "
- + "partitionSize: {}. time cost: {} ms.",
transactionId, totalRetryTime,
- lockContext.getTableToPartitions().size(),
stopWatch.getTime());
- }
+ LOG.info("get delete bitmap lock successfully. txnId: {}.
totalRetryTime: {}. "
+ + "tableSize: {}. cost: {} ms.", transactionId,
totalRetryTime,
+ lockContext.getTableToPartitions().size(),
stopWatch.getTime());
}
private void removeDeleteBitmapUpdateLock(List<OlapTable> tableList, long
transactionId) {
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
