add metrics for channel

Cargo.lock

@@ -844,6 +844,7 @@ dependencies = [
 name = "channel"
 version = "0.1.0"
 dependencies = [
+ "metrics",
  "tokio",
 ]
 

common/channel/Cargo.toml

@@ -5,3 +5,4 @@ edition = "2021"
 
 [dependencies]
 tokio = { version = "1.19.2", features = ["sync", "time"] }
+metrics = { workspace = true }

common/channel/src/channel.rs

@@ -1,6 +1,8 @@
 use crate::error::Error;
-use std::time::Duration;
-use tokio::sync::mpsc::error::TryRecvError;
+use metrics::{register_meter_with_group, Counter, CounterUsize, Histogram, Meter, Sample};
+use std::sync::Arc;
+use std::time::{Duration, Instant};
+use tokio::sync::mpsc::error::{SendError, TryRecvError};
 use tokio::sync::{mpsc, oneshot};
 use tokio::time::timeout;
 
@@ -19,56 +21,139 @@ pub struct Channel<N, Req, Res> {
 }
 
 impl<N, Req, Res> Channel<N, Req, Res> {
-    pub fn unbounded() -> (Sender<N, Req, Res>, Receiver<N, Req, Res>) {
+    pub fn unbounded(name: &str) -> (Sender<N, Req, Res>, Receiver<N, Req, Res>) {
         let (sender, receiver) = mpsc::unbounded_channel();
-        (Sender { chan: sender }, Receiver { chan: receiver })
+
+        let metrics_group = format!("common_channel_{}", name);
+        let metrics_queued = CounterUsize::register_with_group(metrics_group.as_str(), "size");
+
+        (
+            Sender {
+                chan: sender,
+                metrics_send_qps: register_meter_with_group(metrics_group.as_str(), "send"),
+                metrics_queued: metrics_queued.clone(),
+                metrics_timeout: CounterUsize::register_with_group(
+                    metrics_group.as_str(),
+                    "timeout",
+                ),
+            },
+            Receiver {
+                chan: receiver,
+                metrics_recv_qps: register_meter_with_group(metrics_group.as_str(), "recv"),
+                metrics_queued,
+                metrics_queue_latency: Sample::ExpDecay(0.015).register_with_group(
+                    metrics_group.as_str(),
+                    "latency",
+                    1024,
+                ),
+            },
+        )
+    }
+}
+
+enum TimedMessage<N, Req, Res> {
+    Notification(Instant, N),
+    Request(Instant, Req, ResponseSender<Res>),
+}
+
+impl<N, Req, Res> From<Message<N, Req, Res>> for TimedMessage<N, Req, Res> {
+    fn from(value: Message<N, Req, Res>) -> Self {
+        match value {
+            Message::Notification(n) => TimedMessage::Notification(Instant::now(), n),
+            Message::Request(req, res) => TimedMessage::Request(Instant::now(), req, res),
+        }
+    }
+}
+
+impl<N, Req, Res> TimedMessage<N, Req, Res> {
+    fn into_message(self) -> (Instant, Message<N, Req, Res>) {
+        match self {
+            TimedMessage::Notification(since, n) => (since, Message::Notification(n)),
+            TimedMessage::Request(since, req, res) => (since, Message::Request(req, res)),
+        }
     }
 }
 
 pub struct Sender<N, Req, Res> {
-    chan: mpsc::UnboundedSender<Message<N, Req, Res>>,
+    chan: mpsc::UnboundedSender<TimedMessage<N, Req, Res>>,
+
+    metrics_send_qps: Arc<dyn Meter>,
+    metrics_queued: Arc<dyn Counter<usize>>,
+    metrics_timeout: Arc<dyn Counter<usize>>,
 }
 
 impl<N, Req, Res> Clone for Sender<N, Req, Res> {
     fn clone(&self) -> Self {
         Sender {
             chan: self.chan.clone(),
+            metrics_send_qps: self.metrics_send_qps.clone(),
+            metrics_queued: self.metrics_queued.clone(),
+            metrics_timeout: self.metrics_timeout.clone(),
         }
     }
 }
 
 impl<N, Req, Res> Sender<N, Req, Res> {
     pub fn notify(&self, msg: N) -> Result<(), Error<N, Req, Res>> {
-        self.chan
-            .send(Message::Notification(msg))
-            .map_err(|e| Error::SendError(e))
+        self.send(Message::Notification(msg))
     }
 
     pub async fn request(&self, request: Req) -> Result<Res, Error<N, Req, Res>> {
         let (sender, receiver) = oneshot::channel();
 
-        self.chan
-            .send(Message::Request(request, sender))
-            .map_err(|e| Error::SendError(e))?;
+        self.send(Message::Request(request, sender))?;
 
         timeout(DEFAULT_REQUEST_TIMEOUT, receiver)
             .await
-            .map_err(|_| Error::TimeoutError)?
+            .map_err(|_| {
+                self.metrics_timeout.inc(1);
+                Error::TimeoutError
+            })?
             .map_err(|e| Error::RecvError(e))
     }
+
+    fn send(&self, message: Message<N, Req, Res>) -> Result<(), Error<N, Req, Res>> {
+        match self.chan.send(message.into()) {
+            Ok(()) => {
+                self.metrics_send_qps.mark(1);
+                self.metrics_queued.inc(1);
+                Ok(())
+            }
+            Err(e) => {
+                let (_, msg) = e.0.into_message();
+                Err(Error::SendError(SendError(msg)))
+            }
+        }
+    }
 }
 
 pub struct Receiver<N, Req, Res> {
-    chan: mpsc::UnboundedReceiver<Message<N, Req, Res>>,
+    chan: mpsc::UnboundedReceiver<TimedMessage<N, Req, Res>>,
+
+    metrics_recv_qps: Arc<dyn Meter>,
+    metrics_queued: Arc<dyn Counter<usize>>,
+    metrics_queue_latency: Arc<dyn Histogram>,
 }
 
 impl<N, Req, Res> Receiver<N, Req, Res> {
     pub async fn recv(&mut self) -> Option<Message<N, Req, Res>> {
-        self.chan.recv().await
+        let data = self.chan.recv().await?;
+        Some(self.on_recv_data(data))
     }
 
     pub fn try_recv(&mut self) -> Result<Message<N, Req, Res>, TryRecvError> {
-        self.chan.try_recv()
+        let data = self.chan.try_recv()?;
+        Ok(self.on_recv_data(data))
+    }
+
+    fn on_recv_data(&self, data: TimedMessage<N, Req, Res>) -> Message<N, Req, Res> {
+        self.metrics_recv_qps.mark(1);
+        self.metrics_queued.dec(1);
+
+        let (since, msg) = data.into_message();
+        self.metrics_queue_latency.update_since(since);
+
+        msg
     }
 }
 
@@ -91,7 +176,7 @@ mod tests {
 
     #[tokio::test]
     async fn request_response() {
-        let (tx, mut rx) = Channel::<Notification, Request, Response>::unbounded();
+        let (tx, mut rx) = Channel::<Notification, Request, Response>::unbounded("test");
 
         let task1 = async move {
             match rx.recv().await.expect("not dropped") {

node/router/src/libp2p_event_handler.rs

@@ -815,7 +815,7 @@ mod tests {
             let runtime = TestRuntime::default();
             let (network_globals, keypair) = Context::new_network_globals();
             let (network_send, network_recv) = mpsc::unbounded_channel();
-            let (sync_send, sync_recv) = channel::Channel::unbounded();
+            let (sync_send, sync_recv) = channel::Channel::unbounded("test");
             let (chunk_pool_send, _chunk_pool_recv) = mpsc::unbounded_channel();
             let store = LogManager::memorydb(LogConfig::default()).unwrap();
             Self {

node/rpc/src/admin/impl.rs

@@ -4,7 +4,7 @@ use crate::{error, Context};
 use futures::prelude::*;
 use jsonrpsee::core::async_trait;
 use jsonrpsee::core::RpcResult;
-use metrics::DEFAULT_REGISTRY;
+use metrics::{DEFAULT_GROUPING_REGISTRY, DEFAULT_REGISTRY};
 use network::{multiaddr::Protocol, Multiaddr};
 use std::collections::{BTreeMap, HashMap};
 use std::net::IpAddr;
@@ -266,6 +266,21 @@ impl RpcServer for RpcServerImpl {
             }
         }
 
+        for (group_name, metrics) in DEFAULT_GROUPING_REGISTRY.read().get_all() {
+            for (metric_name, metric) in metrics.iter() {
+                let name = format!("{}.{}", group_name, metric_name);
+                match &maybe_prefix {
+                    Some(prefix) if !name.starts_with(prefix) => {}
+                    _ => {
+                        result.insert(
+                            name,
+                            format!("{} {}", metric.get_type(), metric.get_value()),
+                        );
+                    }
+                }
+            }
+        }
+
         Ok(result)
     }
 }

node/sync/src/auto_sync/batcher.rs

@@ -1,7 +1,7 @@
-use crate::{controllers::SyncState, Config, SyncRequest, SyncResponse, SyncSender};
+use crate::{controllers::SyncState, SyncRequest, SyncResponse, SyncSender};
 use anyhow::{bail, Result};
 use serde::{Deserialize, Serialize};
-use std::{collections::HashSet, fmt::Debug, sync::Arc};
+use std::{collections::HashSet, fmt::Debug, sync::Arc, time::Duration};
 use storage_async::Store;
 use tokio::sync::RwLock;
 
@@ -15,18 +15,23 @@ pub enum SyncResult {
 /// Supports to sync files concurrently.
 #[derive(Clone)]
 pub struct Batcher {
-    pub(crate) config: Config,
     capacity: usize,
+    find_peer_timeout: Duration,
     tasks: Arc<RwLock<HashSet<u64>>>, // files to sync
     store: Store,
     sync_send: SyncSender,
 }
 
 impl Batcher {
-    pub fn new(config: Config, capacity: usize, store: Store, sync_send: SyncSender) -> Self {
+    pub fn new(
+        capacity: usize,
+        find_peer_timeout: Duration,
+        store: Store,
+        sync_send: SyncSender,
+    ) -> Self {
         Self {
-            config,
             capacity,
+            find_peer_timeout,
             tasks: Default::default(),
             store,
             sync_send,
@@ -128,7 +133,7 @@ impl Batcher {
 
             // finding peers timeout
             Some(SyncState::FindingPeers { origin, .. })
-                if origin.elapsed() > self.config.find_peer_timeout =>
+                if origin.elapsed() > self.find_peer_timeout =>
             {
                 debug!(%tx_seq, "Terminate file sync due to finding peers timeout");
                 self.terminate_file_sync(tx_seq, false).await;
@@ -137,7 +142,7 @@ impl Batcher {
 
             // connecting peers timeout
             Some(SyncState::ConnectingPeers { origin, .. })
-                if origin.elapsed() > self.config.find_peer_timeout =>
+                if origin.elapsed() > self.find_peer_timeout =>
             {
                 debug!(%tx_seq, "Terminate file sync due to connecting peers timeout");
                 self.terminate_file_sync(tx_seq, false).await;

node/sync/src/auto_sync/batcher_random.rs

@@ -22,6 +22,7 @@ pub struct RandomBatcherState {
 
 #[derive(Clone)]
 pub struct RandomBatcher {
+    config: Config,
     batcher: Batcher,
     sync_store: Arc<SyncStore>,
 }
@@ -34,7 +35,13 @@ impl RandomBatcher {
         sync_store: Arc<SyncStore>,
     ) -> Self {
         Self {
-            batcher: Batcher::new(config, config.max_random_workers, store, sync_send),
+            config,
+            batcher: Batcher::new(
+                config.max_random_workers,
+                config.random_find_peer_timeout,
+                store,
+                sync_send,
+            ),
             sync_store,
         }
     }
@@ -56,7 +63,7 @@ impl RandomBatcher {
             // disable file sync until catched up
             if !catched_up.load(Ordering::Relaxed) {
                 trace!("Cannot sync file in catch-up phase");
-                sleep(self.batcher.config.auto_sync_idle_interval).await;
+                sleep(self.config.auto_sync_idle_interval).await;
                 continue;
             }
 
@@ -73,11 +80,11 @@ impl RandomBatcher {
                         "File sync still in progress or idle, state = {:?}",
                         self.get_state().await
                     );
-                    sleep(self.batcher.config.auto_sync_idle_interval).await;
+                    sleep(self.config.auto_sync_idle_interval).await;
                 }
                 Err(err) => {
                     warn!(%err, "Failed to sync file once, state = {:?}", self.get_state().await);
-                    sleep(self.batcher.config.auto_sync_error_interval).await;
+                    sleep(self.config.auto_sync_error_interval).await;
                 }
             }
         }

node/sync/src/auto_sync/batcher_serial.rs

@@ -23,6 +23,7 @@ use tokio::{
 /// Supports to sync files in sequence concurrently.
 #[derive(Clone)]
 pub struct SerialBatcher {
+    config: Config,
     batcher: Batcher,
 
     /// Next tx seq to sync.
@@ -80,13 +81,17 @@ impl SerialBatcher {
         sync_send: SyncSender,
         sync_store: Arc<SyncStore>,
     ) -> Result<Self> {
-        let capacity = config.max_sequential_workers;
-
         // continue file sync from break point in db
         let (next_tx_seq, max_tx_seq) = sync_store.get_tx_seq_range().await?;
 
         Ok(Self {
-            batcher: Batcher::new(config, capacity, store, sync_send),
+            config,
+            batcher: Batcher::new(
+                config.max_sequential_workers,
+                config.sequential_find_peer_timeout,
+                store,
+                sync_send,
+            ),
             next_tx_seq: Arc::new(AtomicU64::new(next_tx_seq.unwrap_or(0))),
             max_tx_seq: Arc::new(AtomicU64::new(max_tx_seq.unwrap_or(u64::MAX))),
             pending_completed_txs: Default::default(),
@@ -136,7 +141,7 @@ impl SerialBatcher {
             // disable file sync until catched up
             if !catched_up.load(Ordering::Relaxed) {
                 trace!("Cannot sync file in catch-up phase");
-                sleep(self.batcher.config.auto_sync_idle_interval).await;
+                sleep(self.config.auto_sync_idle_interval).await;
                 continue;
             }
 
@@ -157,11 +162,11 @@ impl SerialBatcher {
                         "File sync still in progress or idle, state = {:?}",
                         self.get_state().await
                     );
-                    sleep(self.batcher.config.auto_sync_idle_interval).await;
+                    sleep(self.config.auto_sync_idle_interval).await;
                 }
                 Err(err) => {
                     warn!(%err, "Failed to sync file once, state = {:?}", self.get_state().await);
-                    sleep(self.batcher.config.auto_sync_error_interval).await;
+                    sleep(self.config.auto_sync_error_interval).await;
                 }
             }
         }

node/sync/src/lib.rs

@@ -52,7 +52,9 @@ pub struct Config {
     pub max_sequential_workers: usize,
     pub max_random_workers: usize,
     #[serde(deserialize_with = "deserialize_duration")]
-    pub find_peer_timeout: Duration,
+    pub sequential_find_peer_timeout: Duration,
+    #[serde(deserialize_with = "deserialize_duration")]
+    pub random_find_peer_timeout: Duration,
 }
 
 impl Default for Config {
@@ -61,7 +63,7 @@ impl Default for Config {
             // sync service config
             heartbeat_interval: Duration::from_secs(5),
             auto_sync_enabled: false,
-            max_sync_files: 16,
+            max_sync_files: 32,
             sync_file_by_rpc_enabled: true,
             sync_file_on_announcement_enabled: false,
 
@@ -78,9 +80,10 @@ impl Default for Config {
             // auto sync config
             auto_sync_idle_interval: Duration::from_secs(3),
             auto_sync_error_interval: Duration::from_secs(10),
-            max_sequential_workers: 8,
-            max_random_workers: 4,
-            find_peer_timeout: Duration::from_secs(10),
+            max_sequential_workers: 24,
+            max_random_workers: 8,
+            sequential_find_peer_timeout: Duration::from_secs(60),
+            random_find_peer_timeout: Duration::from_secs(500),
         }
     }
 }

node/sync/src/service.rs

@@ -157,7 +157,7 @@ impl SyncService {
         event_recv: broadcast::Receiver<LogSyncEvent>,
         catch_up_end_recv: oneshot::Receiver<()>,
     ) -> Result<SyncSender> {
-        let (sync_send, sync_recv) = channel::Channel::unbounded();
+        let (sync_send, sync_recv) = channel::Channel::unbounded("sync");
         let store = Store::new(store, executor.clone());
 
         // init auto sync
@@ -912,7 +912,7 @@ mod tests {
             create_file_location_cache(init_peer_id, vec![txs[0].id()]);
 
         let (network_send, mut network_recv) = mpsc::unbounded_channel::<NetworkMessage>();
-        let (_, sync_recv) = channel::Channel::unbounded();
+        let (_, sync_recv) = channel::Channel::unbounded("test");
 
         let mut sync = SyncService {
             config: Config::default(),
@@ -941,7 +941,7 @@ mod tests {
             create_file_location_cache(init_peer_id, vec![txs[0].id()]);
 
         let (network_send, mut network_recv) = mpsc::unbounded_channel::<NetworkMessage>();
-        let (_, sync_recv) = channel::Channel::unbounded();
+        let (_, sync_recv) = channel::Channel::unbounded("test");
 
         let mut sync = SyncService {
             config: Config::default(),

run/config-testnet-standard.toml

@@ -228,11 +228,7 @@ reward_contract_address = "0x0496D0817BD8519e0de4894Dc379D35c35275609"
 auto_sync_enabled = true
 
 #  Maximum number of files in sync from other peers simultaneously.
-max_sync_files = 32
-
-# Timeout to terminate a file sync when automatically sync from other peers.
-# If timeout, terminated file sync will be triggered later.
-# find_peer_timeout = "10s"
+# max_sync_files = 32
 
 # Enable to start a file sync via RPC (e.g. `admin_startSyncFile`).
 # sync_file_by_rpc_enabled = true
@@ -241,10 +237,10 @@ max_sync_files = 32
 # sync_file_on_announcement_enabled = false
 
 # Maximum threads to sync files in sequence.
-max_sequential_workers = 24
+# max_sequential_workers = 24
 
 # Maximum threads to sync files randomly.
-# max_random_workers = 4
+# max_random_workers = 8
 
 #######################################################################
 ###                File Location Cache Options                      ###
@@ -265,4 +261,4 @@ max_sequential_workers = 24
 
 # Validity period of location information.
 # If the timestamp in the storage location information exceeds this duration from the current time, it will be removed from the cache.
-# entry_expiration_time_secs = 3600
+# entry_expiration_time_secs = 3600

run/config-testnet-turbo.toml

@@ -228,11 +228,7 @@ reward_contract_address = "0x51998C4d486F406a788B766d93510980ae1f9360"
 auto_sync_enabled = true
 
 #  Maximum number of files in sync from other peers simultaneously.
-max_sync_files = 32
-
-# Timeout to terminate a file sync when automatically sync from other peers.
-# If timeout, terminated file sync will be triggered later.
-# find_peer_timeout = "10s"
+# max_sync_files = 32
 
 # Enable to start a file sync via RPC (e.g. `admin_startSyncFile`).
 # sync_file_by_rpc_enabled = true
@@ -241,10 +237,10 @@ max_sync_files = 32
 # sync_file_on_announcement_enabled = false
 
 # Maximum threads to sync files in sequence.
-max_sequential_workers = 24
+# max_sequential_workers = 24
 
 # Maximum threads to sync files randomly.
-# max_random_workers = 4
+# max_random_workers = 8
 
 #######################################################################
 ###                File Location Cache Options                      ###
@@ -265,4 +261,4 @@ max_sequential_workers = 24
 
 # Validity period of location information.
 # If the timestamp in the storage location information exceeds this duration from the current time, it will be removed from the cache.
-# entry_expiration_time_secs = 3600
+# entry_expiration_time_secs = 3600

run/config.toml

@@ -227,11 +227,7 @@
 # auto_sync_enabled = false
 
 #  Maximum number of files in sync from other peers simultaneously.
-# max_sync_files = 16
-
-# Timeout to terminate a file sync when automatically sync from other peers.
-# If timeout, terminated file sync will be triggered later.
-# find_peer_timeout = "10s"
+# max_sync_files = 32
 
 # Enable to start a file sync via RPC (e.g. `admin_startSyncFile`).
 # sync_file_by_rpc_enabled = true
@@ -240,10 +236,10 @@
 # sync_file_on_announcement_enabled = false
 
 # Maximum threads to sync files in sequence.
-# max_sequential_workers = 8
+# max_sequential_workers = 24
 
 # Maximum threads to sync files randomly.
-# max_random_workers = 4
+# max_random_workers = 8
 
 #######################################################################
 ###                File Location Cache Options                      ###
@@ -264,4 +260,4 @@
 
 # Validity period of location information.
 # If the timestamp in the storage location information exceeds this duration from the current time, it will be removed from the cache.
-# entry_expiration_time_secs = 3600
+# entry_expiration_time_secs = 3600