The performance of groups describe command is unstable #9
Description
Sometimes it takes much time.
% ./build2/snctl-cpp groups describe sub --lag | grep takes
describe_group takes 3288 ms
query_committed_offsets takes 1 ms
query_end_offsets takes 6 ms
% ./build2/snctl-cpp groups describe sub --lag | grep takes
describe_group takes 3019 ms
query_committed_offsets takes 1 ms
query_end_offsets takes 9 ms
% ./build2/snctl-cpp groups describe sub --lag | grep takes
describe_group takes 2013 ms
query_committed_offsets takes 0 ms
query_end_offsets takes 4 ms
% ./build2/snctl-cpp groups describe sub --lag | grep takes
describe_group takes 3016 ms
query_committed_offsets takes 0 ms
query_end_offsets takes 4 ms
% ./build2/snctl-cpp groups describe sub --lag | grep takes
describe_group takes 3012 ms
query_committed_offsets takes 1 ms
query_end_offsets takes 6 ms
The result is based on the following patch (on 9cdee53) that measures the RPC latency:
diff --git a/include/snctl-cpp/groups/describe_group.h b/include/snctl-cpp/groups/describe_group.h
index bedaae3..d1d1465 100644
--- a/include/snctl-cpp/groups/describe_group.h
+++ b/include/snctl-cpp/groups/describe_group.h
@@ -15,6 +15,7 @@
*/
#pragma once
+#include "snctl-cpp/perf.h"
#include "snctl-cpp/raii_helper.h"
#include "snctl-cpp/rk_event_wrapper.h"
#include <cassert>
@@ -23,6 +24,7 @@
#include <iostream>
#include <librdkafka/rdkafka.h>
#include <map>
+#include <memory>
#include <ostream>
#include <sstream>
#include <stdexcept>
@@ -133,10 +135,12 @@ query_end_offsets(rd_kafka_t *rk, rd_kafka_queue_t *rkqu,
inline void describe_group(rd_kafka_t *rk, rd_kafka_queue_t *rkqu,
const std::string &group, bool show_lag) {
const char *groups[1] = {group.c_str()};
+ auto perf = std::make_unique<Perf>("describe_group");
rd_kafka_DescribeConsumerGroups(rk, groups, 1, nullptr, rkqu);
try {
auto event = RdKafkaEvent::poll(rkqu);
+ perf.reset();
const auto *result =
rd_kafka_event_DescribeConsumerGroups_result(event.handle());
assert(result != nullptr);
@@ -229,9 +233,12 @@ inline void describe_group(rd_kafka_t *rk, rd_kafka_queue_t *rkqu,
}
}
+ perf = std::make_unique<Perf>("query_committed_offsets");
const auto committed_offsets =
query_committed_offsets(rk, rkqu, group_id, rk_topic_partitions);
+ perf = std::make_unique<Perf>("query_end_offsets");
const auto end_offsets = query_end_offsets(rk, rkqu, rk_topic_partitions);
+ perf.reset();
std::cout << "Offsets info for group '" << group_id << "' with "
<< committed_offsets.size()
<< " topic-partitions:" << std::endl;
diff --git a/include/snctl-cpp/perf.h b/include/snctl-cpp/perf.h
new file mode 100644
index 0000000..52a1402
--- /dev/null
+++ b/include/snctl-cpp/perf.h
@@ -0,0 +1,37 @@
+/**
+ * Copyright 2025 Yunze Xu
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+#pragma once
+
+#include <chrono>
+#include <iostream>
+
+class Perf final {
+public:
+ explicit Perf(std::string &&name) : name_(std::move(name)) {}
+
+ ~Perf() {
+ auto now = std::chrono::high_resolution_clock::now();
+ auto duration =
+ std::chrono::duration_cast<std::chrono::milliseconds>(now - start_time_)
+ .count();
+ std::cout << name_ << " takes " << duration << " ms" << std::endl;
+ }
+
+private:
+ std::chrono::time_point<std::chrono::high_resolution_clock> start_time_ =
+ std::chrono::high_resolution_clock::now();
+ std::string name_;
+};