feat(state-keeper): track the time that individual transactions spend…

… in mempool (#941)

## What ❔

We want to track the avergae/median time users' transactions spend in
the mempool

## Why ❔

To be able to reason about UX.

Note: I also track the time it takes to produce this tracking just to
make sure it's negligible.

core/lib/zksync_core/src/state_keeper/io/seal_logic.rs

@@ -6,6 +6,7 @@ use std::{
     time::{Duration, Instant},
 };
 
+use chrono::Utc;
 use itertools::Itertools;
 use multivm::{
     interface::{FinishedL1Batch, L1BatchEnv},
@@ -38,7 +39,10 @@ use crate::{
     metrics::{BlockStage, MiniblockStage, APP_METRICS},
     state_keeper::{
         extractors,
-        metrics::{L1BatchSealStage, MiniblockSealStage, L1_BATCH_METRICS, MINIBLOCK_METRICS},
+        metrics::{
+            L1BatchSealStage, MiniblockSealStage, KEEPER_METRICS, L1_BATCH_METRICS,
+            MINIBLOCK_METRICS,
+        },
         types::ExecutionMetricsForCriteria,
         updates::{MiniblockSealCommand, UpdatesManager},
     },
@@ -475,6 +479,17 @@ impl MiniblockSealCommand {
 
         transaction.commit().await.unwrap();
         progress.observe(None);
+
+        let progress = MINIBLOCK_METRICS.start(MiniblockSealStage::ReportTxMetrics, is_fictive);
+        self.miniblock.executed_transactions.iter().for_each(|tx| {
+            KEEPER_METRICS
+                .transaction_inclusion_delay
+                .observe(Duration::from_millis(
+                    Utc::now().timestamp_millis() as u64 - tx.transaction.received_timestamp_ms,
+                ))
+        });
+        progress.observe(Some(self.miniblock.executed_transactions.len()));
+
         self.report_miniblock_metrics(started_at, current_l2_virtual_block_number);
     }
 

core/lib/zksync_core/src/state_keeper/metrics.rs

@@ -52,6 +52,9 @@ pub(crate) struct StateKeeperMetrics {
     /// Time spent waiting for the header of a previous miniblock.
     #[metrics(buckets = Buckets::LATENCIES)]
     pub load_previous_miniblock_header: Histogram<Duration>,
+    /// The time it takes for transactions to be included in a block. Representative of the time user must wait before their transaction is confirmed.
+    #[metrics(buckets = Buckets::LATENCIES)]
+    pub transaction_inclusion_delay: Histogram<Duration>,
     /// Time spent by the state keeper on transaction execution.
     #[metrics(buckets = Buckets::LATENCIES)]
     pub tx_execution_time: Family<TxExecutionStage, Histogram<Duration>>,
@@ -249,6 +252,7 @@ pub(super) enum MiniblockSealStage {
     ExtractL2ToL1Logs,
     InsertL2ToL1Logs,
     CommitMiniblock,
+    ReportTxMetrics,
 }
 
 #[derive(Debug, Clone, Copy, PartialEq, Eq, Hash, EncodeLabelSet)]