feat: introduce wal benchmarker (#3446)

* feat: introduce wal benchmarker

* chore: add log store metrics

* chore: add some comments to wal benchmarker

* fix: ci

* chore: add more metrics for kafka logstore

* chore: add more timers for kafka logstore

* chore: add more configs

* chore: move humantime to common dependencies

* refactor: refactor wal benchmarker

* fix: apply suggestions from code review

* doc: add a simple README for wal benchmarker

* fix: Cargo.toml

* fix: clippy

* chore: rename wal.rs to wal_bench.rs

* fix: compile

src/log-store/Cargo.toml

@@ -26,6 +26,8 @@ common-time.workspace = true
 common-wal.workspace = true
 futures.workspace = true
 futures-util.workspace = true
+lazy_static.workspace = true
+prometheus.workspace = true
 protobuf = { version = "2", features = ["bytes"] }
 raft-engine.workspace = true
 rskafka.workspace = true

src/log-store/src/kafka.rs

@@ -12,6 +12,7 @@
 // See the License for the specific language governing permissions and
 // limitations under the License.
 
+use std::mem::size_of;
 pub(crate) mod client_manager;
 pub mod log_store;
 pub(crate) mod util;
@@ -69,6 +70,10 @@ impl Entry for EntryImpl {
     fn namespace(&self) -> Self::Namespace {
         self.ns.clone()
     }
+
+    fn estimated_size(&self) -> usize {
+        size_of::<Self>() + self.data.capacity() * size_of::<u8>() + self.ns.topic.capacity()
+    }
 }
 
 impl Display for EntryImpl {
@@ -82,3 +87,27 @@ impl Display for EntryImpl {
         )
     }
 }
+
+#[cfg(test)]
+mod tests {
+    use std::mem::size_of;
+
+    use store_api::logstore::entry::Entry;
+
+    use crate::kafka::{EntryImpl, NamespaceImpl};
+
+    #[test]
+    fn test_estimated_size() {
+        let entry = EntryImpl {
+            data: Vec::with_capacity(100),
+            id: 0,
+            ns: NamespaceImpl {
+                region_id: 0,
+                topic: String::with_capacity(10),
+            },
+        };
+        let expected = size_of::<EntryImpl>() + 100 * size_of::<u8>() + 10;
+        let got = entry.estimated_size();
+        assert_eq!(expected, got);
+    }
+}

src/log-store/src/kafka/log_store.rs

@@ -22,7 +22,7 @@ use futures_util::StreamExt;
 use rskafka::client::consumer::{StartOffset, StreamConsumerBuilder};
 use rskafka::client::partition::OffsetAt;
 use snafu::ResultExt;
-use store_api::logstore::entry::Id as EntryId;
+use store_api::logstore::entry::{Entry as EntryTrait, Id as EntryId};
 use store_api::logstore::entry_stream::SendableEntryStream;
 use store_api::logstore::namespace::Id as NamespaceId;
 use store_api::logstore::{AppendBatchResponse, AppendResponse, LogStore};
@@ -32,6 +32,7 @@ use crate::kafka::client_manager::{ClientManager, ClientManagerRef};
 use crate::kafka::util::offset::Offset;
 use crate::kafka::util::record::{maybe_emit_entry, Record, RecordProducer};
 use crate::kafka::{EntryImpl, NamespaceImpl};
+use crate::metrics;
 
 /// A log store backed by Kafka.
 #[derive(Debug)]
@@ -86,6 +87,15 @@ impl LogStore for KafkaLogStore {
     /// Appends a batch of entries and returns a response containing a map where the key is a region id
     /// while the value is the id of the last successfully written entry of the region.
     async fn append_batch(&self, entries: Vec<Self::Entry>) -> Result<AppendBatchResponse> {
+        metrics::METRIC_KAFKA_APPEND_BATCH_CALLS_TOTAL.inc();
+        metrics::METRIC_KAFKA_APPEND_BATCH_BYTES_TOTAL.inc_by(
+            entries
+                .iter()
+                .map(EntryTrait::estimated_size)
+                .sum::<usize>() as u64,
+        );
+        let _timer = metrics::METRIC_KAFKA_APPEND_BATCH_ELAPSED.start_timer();
+
         if entries.is_empty() {
             return Ok(AppendBatchResponse::default());
         }
@@ -124,6 +134,9 @@ impl LogStore for KafkaLogStore {
         ns: &Self::Namespace,
         entry_id: EntryId,
     ) -> Result<SendableEntryStream<Self::Entry, Self::Error>> {
+        metrics::METRIC_KAFKA_READ_CALLS_TOTAL.inc();
+        let _timer = metrics::METRIC_KAFKA_READ_ELAPSED.start_timer();
+
         // Gets the client associated with the topic.
         let client = self
             .client_manager
@@ -183,6 +196,9 @@ impl LogStore for KafkaLogStore {
                     })?;
                 let (kafka_record, offset) = (record_and_offset.record, record_and_offset.offset);
 
+                metrics::METRIC_KAFKA_READ_RECORD_BYTES_TOTAL
+                    .inc_by(kafka_record.approximate_size() as u64);
+
                 debug!(
                     "Read a record at offset {} for ns {}, high watermark: {}",
                     offset, ns_clone, high_watermark

src/log-store/src/kafka/util/record.rs

@@ -25,6 +25,7 @@ use crate::error::{
 use crate::kafka::client_manager::ClientManagerRef;
 use crate::kafka::util::offset::Offset;
 use crate::kafka::{EntryId, EntryImpl, NamespaceImpl};
+use crate::metrics;
 
 /// The current version of Record.
 pub(crate) const VERSION: u32 = 0;
@@ -97,6 +98,7 @@ impl TryFrom<Record> for KafkaRecord {
     }
 }
 
+// TODO(niebayes): improve the performance of decoding kafka record.
 impl TryFrom<KafkaRecord> for Record {
     type Error = crate::error::Error;
 
@@ -150,6 +152,7 @@ impl RecordProducer {
 
     /// Produces the buffered entries to Kafka sever. Those entries may span several Kafka records.
     /// Returns the offset of the last successfully produced record.
+    // TODO(niebayes): maybe requires more fine-grained metrics to measure stages of writing to kafka.
     pub(crate) async fn produce(self, client_manager: &ClientManagerRef) -> Result<Offset> {
         ensure!(!self.entries.is_empty(), EmptyEntriesSnafu);
 
@@ -173,6 +176,11 @@ impl RecordProducer {
         for entry in self.entries {
             for record in build_records(entry, max_record_size) {
                 let kafka_record = KafkaRecord::try_from(record)?;
+
+                metrics::METRIC_KAFKA_PRODUCE_RECORD_COUNTS.inc();
+                metrics::METRIC_KAFKA_PRODUCE_RECORD_BYTES_TOTAL
+                    .inc_by(kafka_record.approximate_size() as u64);
+
                 // Records of a certain region cannot be produced in parallel since their order must be static.
                 let offset = producer
                     .produce(kafka_record.clone())

src/log-store/src/lib.rs

@@ -17,6 +17,7 @@
 
 pub mod error;
 pub mod kafka;
+pub mod metrics;
 mod noop;
 pub mod raft_engine;
 pub mod test_util;

src/log-store/src/metrics.rs

@@ -0,0 +1,107 @@
+// Copyright 2023 Greptime Team
+//
+// 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.
+
+use lazy_static::lazy_static;
+use prometheus::*;
+
+/// Logstore label.
+pub const LOGSTORE_LABEL: &str = "logstore";
+/// Operation type label.
+pub const OPTYPE_LABEL: &str = "optype";
+
+lazy_static! {
+    /// Counters of bytes of each operation on a logstore.
+    pub static ref METRIC_LOGSTORE_OP_BYTES_TOTAL: IntCounterVec = register_int_counter_vec!(
+        "greptime_logstore_op_bytes_total",
+        "logstore operation bytes total",
+        &[LOGSTORE_LABEL, OPTYPE_LABEL],
+    )
+    .unwrap();
+    /// Counter of bytes of the append_batch operation on the kafka logstore.
+    pub static ref METRIC_KAFKA_APPEND_BATCH_BYTES_TOTAL: IntCounter = METRIC_LOGSTORE_OP_BYTES_TOTAL.with_label_values(
+        &["kafka", "append_batch"],
+    );
+    /// Counter of bytes of the read operation on the kafka logstore.
+    pub static ref METRIC_KAFKA_READ_BYTES_TOTAL: IntCounter = METRIC_LOGSTORE_OP_BYTES_TOTAL.with_label_values(
+        &["kafka", "read"],
+    );
+    /// Counter of bytes of the append_batch operation on the raft-engine logstore.
+    pub static ref METRIC_RAFT_ENGINE_APPEND_BATCH_BYTES_TOTAL: IntCounter = METRIC_LOGSTORE_OP_BYTES_TOTAL.with_label_values(
+        &["raft-engine", "append_batch"],
+    );
+    /// Counter of bytes of the read operation on the raft-engine logstore.
+    pub static ref METRIC_RAFT_ENGINE_READ_BYTES_TOTAL: IntCounter = METRIC_LOGSTORE_OP_BYTES_TOTAL.with_label_values(
+        &["raft-engine", "read"],
+    );
+
+    /// Counter of bytes of the records read by the kafka logstore.
+    pub static ref METRIC_KAFKA_READ_RECORD_BYTES_TOTAL: IntCounter = register_int_counter!(
+        "greptime_kafka_read_record_bytes_total",
+        "kafka read record bytes total"
+    ).unwrap();
+
+    /// Counter of the numbers of the records produced by the kafka logstore.
+    pub static ref METRIC_KAFKA_PRODUCE_RECORD_COUNTS: IntCounter = register_int_counter!(
+        "greptime_kafka_produce_record_counts",
+        "kafka produce record counts",
+    ).unwrap();
+
+    /// Counter of bytes of the records produced by the kafka logstore.
+    pub static ref METRIC_KAFKA_PRODUCE_RECORD_BYTES_TOTAL: IntCounter = register_int_counter!(
+        "greptime_kafka_produce_record_bytes_total",
+        "kafka produce record bytes total"
+    ).unwrap();
+
+    /// Counters of calls of each operation on a logstore.
+    pub static ref METRIC_LOGSTORE_OP_CALLS_TOTAL: IntCounterVec = register_int_counter_vec!(
+        "greptime_logstore_op_calls_total",
+        "logstore operation calls total",
+        &[LOGSTORE_LABEL, OPTYPE_LABEL],
+    )
+    .unwrap();
+    /// Counter of calls of the append_batch operation on the kafka logstore.
+    pub static ref METRIC_KAFKA_APPEND_BATCH_CALLS_TOTAL: IntCounter = METRIC_LOGSTORE_OP_CALLS_TOTAL.with_label_values(
+        &["kafka", "append_batch"],
+    );
+    /// Counter of calls of the read operation on the kafka logstore.
+    pub static ref METRIC_KAFKA_READ_CALLS_TOTAL: IntCounter = METRIC_LOGSTORE_OP_CALLS_TOTAL.with_label_values(
+        &["kafka", "read"],
+    );
+    /// Counter of calls of the append_batch operation on the raft-engine logstore.
+    pub static ref METRIC_RAFT_ENGINE_APPEND_BATCH_CALLS_TOTAL: IntCounter = METRIC_LOGSTORE_OP_CALLS_TOTAL.with_label_values(
+        &["raft-engine", "append_batch"],
+    );
+    /// Counter of calls of the read operation on the raft-engine logstore.
+    pub static ref METRIC_RAFT_ENGINE_READ_CALLS_TOTAL: IntCounter = METRIC_LOGSTORE_OP_CALLS_TOTAL.with_label_values(
+        &["raft-engine", "read"],
+    );
+
+    /// Timer of operations on a logstore.
+    pub static ref METRIC_LOGSTORE_OP_ELAPSED: HistogramVec = register_histogram_vec!(
+        "greptime_logstore_op_elapsed",
+        "logstore operation elapsed",
+        &[LOGSTORE_LABEL, OPTYPE_LABEL],
+    )
+    .unwrap();
+    /// Timer of the append_batch operation on the kafka logstore.
+    pub static ref METRIC_KAFKA_APPEND_BATCH_ELAPSED: Histogram = METRIC_LOGSTORE_OP_ELAPSED.with_label_values(&["kafka", "append_batch"]);
+    /// Timer of the append_batch operation on the kafka logstore.
+    /// This timer only measures the duration of the read operation, not measures the total duration of replay.
+    pub static ref METRIC_KAFKA_READ_ELAPSED: Histogram = METRIC_LOGSTORE_OP_ELAPSED.with_label_values(&["kafka", "read"]);
+    /// Timer of the append_batch operation on the raft-engine logstore.
+    pub static ref METRIC_RAFT_ENGINE_APPEND_BATCH_ELAPSED: Histogram = METRIC_LOGSTORE_OP_ELAPSED.with_label_values(&["raft-engine", "append_batch"]);
+    /// Timer of the append_batch operation on the raft-engine logstore.
+    /// This timer only measures the duration of the read operation, not measures the total duration of replay.
+    pub static ref METRIC_RAFT_ENGINE_READ_ELAPSED: Histogram = METRIC_LOGSTORE_OP_ELAPSED.with_label_values(&["raft-engine", "read"]);
+}

src/log-store/src/noop.rs

@@ -50,6 +50,10 @@ impl Entry for EntryImpl {
     fn namespace(&self) -> Self::Namespace {
         Default::default()
     }
+
+    fn estimated_size(&self) -> usize {
+        0
+    }
 }
 
 #[async_trait::async_trait]

src/log-store/src/raft_engine.rs

@@ -13,6 +13,7 @@
 // limitations under the License.
 
 use std::hash::{Hash, Hasher};
+use std::mem::size_of;
 
 use store_api::logstore::entry::{Entry, Id as EntryId};
 use store_api::logstore::namespace::{Id as NamespaceId, Namespace};
@@ -83,4 +84,25 @@ impl Entry for EntryImpl {
             ..Default::default()
         }
     }
+
+    fn estimated_size(&self) -> usize {
+        size_of::<Self>() + self.data.capacity() * size_of::<u8>()
+    }
+}
+
+#[cfg(test)]
+mod tests {
+    use std::mem::size_of;
+
+    use store_api::logstore::entry::Entry;
+
+    use crate::raft_engine::protos::logstore::EntryImpl;
+
+    #[test]
+    fn test_estimated_size() {
+        let entry = EntryImpl::create(1, 1, Vec::with_capacity(100));
+        let expected = size_of::<EntryImpl>() + 100;
+        let got = entry.estimated_size();
+        assert_eq!(expected, got);
+    }
 }

src/log-store/src/raft_engine/log_store.rs

@@ -25,7 +25,7 @@ use common_wal::config::raft_engine::RaftEngineConfig;
 use common_wal::options::WalOptions;
 use raft_engine::{Config, Engine, LogBatch, MessageExt, ReadableSize, RecoveryMode};
 use snafu::{ensure, ResultExt};
-use store_api::logstore::entry::Id as EntryId;
+use store_api::logstore::entry::{Entry as EntryTrait, Id as EntryId};
 use store_api::logstore::entry_stream::SendableEntryStream;
 use store_api::logstore::namespace::{Id as NamespaceId, Namespace as NamespaceTrait};
 use store_api::logstore::{AppendBatchResponse, AppendResponse, LogStore};
@@ -35,6 +35,7 @@ use crate::error::{
     IllegalNamespaceSnafu, IllegalStateSnafu, OverrideCompactedEntrySnafu, RaftEngineSnafu, Result,
     StartGcTaskSnafu, StopGcTaskSnafu,
 };
+use crate::metrics;
 use crate::raft_engine::backend::SYSTEM_NAMESPACE;
 use crate::raft_engine::protos::logstore::{EntryImpl, NamespaceImpl as Namespace};
 
@@ -248,6 +249,15 @@ impl LogStore for RaftEngineLogStore {
     /// Appends a batch of entries to logstore. `RaftEngineLogStore` assures the atomicity of
     /// batch append.
     async fn append_batch(&self, entries: Vec<Self::Entry>) -> Result<AppendBatchResponse> {
+        metrics::METRIC_RAFT_ENGINE_APPEND_BATCH_CALLS_TOTAL.inc();
+        metrics::METRIC_RAFT_ENGINE_APPEND_BATCH_BYTES_TOTAL.inc_by(
+            entries
+                .iter()
+                .map(EntryTrait::estimated_size)
+                .sum::<usize>() as u64,
+        );
+        let _timer = metrics::METRIC_RAFT_ENGINE_APPEND_BATCH_ELAPSED.start_timer();
+
         ensure!(self.started(), IllegalStateSnafu);
         if entries.is_empty() {
             return Ok(AppendBatchResponse::default());
@@ -280,6 +290,9 @@ impl LogStore for RaftEngineLogStore {
         ns: &Self::Namespace,
         entry_id: EntryId,
     ) -> Result<SendableEntryStream<'_, Self::Entry, Self::Error>> {
+        metrics::METRIC_RAFT_ENGINE_READ_CALLS_TOTAL.inc();
+        let _timer = metrics::METRIC_RAFT_ENGINE_READ_ELAPSED.start_timer();
+
         ensure!(self.started(), IllegalStateSnafu);
         let engine = self.engine.clone();
 

src/meta-srv/Cargo.toml

@@ -33,7 +33,7 @@ etcd-client.workspace = true
 futures.workspace = true
 h2 = "0.3"
 http-body = "0.4"
-humantime = "2.1"
+humantime.workspace = true
 humantime-serde.workspace = true
 itertools.workspace = true
 lazy_static.workspace = true

src/query/Cargo.toml

@@ -40,7 +40,7 @@ datatypes.workspace = true
 futures = "0.3"
 futures-util.workspace = true
 greptime-proto.workspace = true
-humantime = "2.1"
+humantime.workspace = true
 lazy_static.workspace = true
 meter-core.workspace = true
 meter-macros.workspace = true

src/store-api/src/logstore/entry.rs

@@ -35,4 +35,7 @@ pub trait Entry: Send + Sync {
 
     /// Returns the namespace of the entry.
     fn namespace(&self) -> Self::Namespace;
+
+    /// Computes the estimated size in bytes of the entry.
+    fn estimated_size(&self) -> usize;
 }

src/store-api/src/logstore/entry_stream.rs

@@ -31,6 +31,7 @@ pub type SendableEntryStream<'a, I, E> = Pin<Box<dyn Stream<Item = Result<Vec<I>
 #[cfg(test)]
 mod tests {
     use std::any::Any;
+    use std::mem::size_of;
     use std::task::{Context, Poll};
 
     use common_error::ext::StackError;
@@ -87,6 +88,10 @@ mod tests {
         fn namespace(&self) -> Self::Namespace {
             Namespace {}
         }
+
+        fn estimated_size(&self) -> usize {
+            self.data.capacity() * size_of::<u8>()
+        }
     }
 
     impl SimpleEntry {

src/table/Cargo.toml

@@ -29,7 +29,7 @@ datafusion-physical-expr.workspace = true
 datatypes.workspace = true
 derive_builder.workspace = true
 futures.workspace = true
-humantime = "2.1"
+humantime.workspace = true
 humantime-serde.workspace = true
 paste = "1.0"
 serde.workspace = true