From 8322dc32b444aac490c4bf8e6e3528186e75dd3c Mon Sep 17 00:00:00 2001 From: Ivan Schasny Date: Fri, 23 Aug 2024 10:30:17 +0100 Subject: [PATCH 1/9] feat: add cbt metrics --- Cargo.lock | 2 + .../config/src/configs/base_token_adjuster.rs | 28 +++ core/lib/config/src/testonly.rs | 2 + .../src/base_token_adjuster.rs | 8 + .../proto/config/base_token_adjuster.proto | 2 + core/node/base_token_adjuster/Cargo.toml | 3 +- .../src/base_token_ratio_persister.rs | 162 ++++++++++++------ core/node/base_token_adjuster/src/lib.rs | 1 + core/node/base_token_adjuster/src/metrics.rs | 34 ++++ 9 files changed, 185 insertions(+), 57 deletions(-) create mode 100644 core/node/base_token_adjuster/src/metrics.rs diff --git a/Cargo.lock b/Cargo.lock index 8fd242326638..2e0579751380 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -8050,6 +8050,7 @@ dependencies = [ "rand 0.8.5", "tokio", "tracing", + "vise", "zksync_config", "zksync_contracts", "zksync_dal", @@ -8057,6 +8058,7 @@ dependencies = [ "zksync_external_price_api", "zksync_node_fee_model", "zksync_types", + "zksync_utils", ] [[package]] diff --git a/core/lib/config/src/configs/base_token_adjuster.rs b/core/lib/config/src/configs/base_token_adjuster.rs index 0ae451a62d9c..c8a0fe6312e3 100644 --- a/core/lib/config/src/configs/base_token_adjuster.rs +++ b/core/lib/config/src/configs/base_token_adjuster.rs @@ -26,6 +26,12 @@ const DEFAULT_L1_TX_SENDING_MAX_ATTEMPTS: u32 = 3; /// Default number of milliseconds to sleep between receipt checking attempts const DEFAULT_L1_RECEIPT_CHECKING_SLEEP_MS: u64 = 30_000; +/// Default maximum number of attempts to fetch price from a remote API +const DEFAULT_PRICE_FETCHING_MAX_ATTEMPTS: u32 = 3; + +/// Default number of milliseconds to sleep between price fetching attempts +const DEFAULT_PRICE_FETCHING_SLEEP_MS: u64 = 5_000; + /// Default number of milliseconds to sleep between transaction sending attempts const DEFAULT_L1_TX_SENDING_SLEEP_MS: u64 = 30_000; @@ -73,6 +79,14 @@ pub struct BaseTokenAdjusterConfig { #[serde(default = "BaseTokenAdjusterConfig::default_l1_tx_sending_sleep_ms")] pub l1_tx_sending_sleep_ms: u64, + /// Maximum number of attempts to fetch quote from a remote API before failing over + #[serde(default = "BaseTokenAdjusterConfig::default_price_fetching_max_attempts")] + pub price_fetching_max_attempts: u32, + + /// Number of seconds to sleep between price fetching attempts + #[serde(default = "BaseTokenAdjusterConfig::default_price_fetching_sleep_ms")] + pub price_fetching_sleep_ms: u64, + /// Defines whether base_token_adjuster should halt the process if there was an error while /// fetching or persisting the quote. Generally that should be set to false to not to halt /// the server process if an external api is not available or if L1 is congested. @@ -93,6 +107,8 @@ impl Default for BaseTokenAdjusterConfig { l1_receipt_checking_sleep_ms: Self::default_l1_receipt_checking_sleep_ms(), l1_tx_sending_max_attempts: Self::default_l1_tx_sending_max_attempts(), l1_tx_sending_sleep_ms: Self::default_l1_tx_sending_sleep_ms(), + price_fetching_sleep_ms: Self::default_price_fetching_sleep_ms(), + price_fetching_max_attempts: Self::default_price_fetching_max_attempts(), halt_on_error: Self::default_halt_on_error(), } } @@ -135,6 +151,10 @@ impl BaseTokenAdjusterConfig { Duration::from_millis(self.l1_tx_sending_sleep_ms) } + pub fn price_fetching_sleep_duration(&self) -> Duration { + Duration::from_millis(self.price_fetching_sleep_ms) + } + pub fn default_l1_receipt_checking_max_attempts() -> u32 { DEFAULT_L1_RECEIPT_CHECKING_MAX_ATTEMPTS } @@ -151,6 +171,14 @@ impl BaseTokenAdjusterConfig { DEFAULT_L1_TX_SENDING_SLEEP_MS } + pub fn default_price_fetching_sleep_ms() -> u64 { + DEFAULT_PRICE_FETCHING_SLEEP_MS + } + + pub fn default_price_fetching_max_attempts() -> u32 { + DEFAULT_PRICE_FETCHING_MAX_ATTEMPTS + } + pub fn default_max_tx_gas() -> u64 { DEFAULT_MAX_TX_GAS } diff --git a/core/lib/config/src/testonly.rs b/core/lib/config/src/testonly.rs index 1f4bfbc0265b..e028c3d3aec0 100644 --- a/core/lib/config/src/testonly.rs +++ b/core/lib/config/src/testonly.rs @@ -1045,6 +1045,8 @@ impl Distribution for Enc l1_receipt_checking_sleep_ms: self.sample(rng), l1_tx_sending_max_attempts: self.sample(rng), l1_tx_sending_sleep_ms: self.sample(rng), + price_fetching_max_attempts: self.sample(rng), + price_fetching_sleep_ms: self.sample(rng), halt_on_error: self.sample(rng), } } diff --git a/core/lib/protobuf_config/src/base_token_adjuster.rs b/core/lib/protobuf_config/src/base_token_adjuster.rs index d68db5fd9796..542cbfd6d698 100644 --- a/core/lib/protobuf_config/src/base_token_adjuster.rs +++ b/core/lib/protobuf_config/src/base_token_adjuster.rs @@ -30,6 +30,12 @@ impl ProtoRepr for proto::BaseTokenAdjuster { l1_receipt_checking_max_attempts: self .l1_receipt_checking_max_attempts .unwrap_or(Self::Type::default_l1_receipt_checking_max_attempts()), + price_fetching_sleep_ms: self + .l1_receipt_checking_sleep_ms + .unwrap_or(Self::Type::default_price_fetching_sleep_ms()), + price_fetching_max_attempts: self + .l1_receipt_checking_max_attempts + .unwrap_or(Self::Type::default_price_fetching_max_attempts()), l1_tx_sending_max_attempts: self .l1_tx_sending_max_attempts .unwrap_or(Self::Type::default_l1_tx_sending_max_attempts()), @@ -47,6 +53,8 @@ impl ProtoRepr for proto::BaseTokenAdjuster { l1_receipt_checking_max_attempts: Some(this.l1_receipt_checking_max_attempts), l1_tx_sending_max_attempts: Some(this.l1_tx_sending_max_attempts), l1_tx_sending_sleep_ms: Some(this.l1_tx_sending_sleep_ms), + price_fetching_max_attempts: Some(this.price_fetching_max_attempts), + price_fetching_sleep_ms: Some(this.price_fetching_sleep_ms), max_tx_gas: Some(this.max_tx_gas), default_priority_fee_per_gas: Some(this.default_priority_fee_per_gas), max_acceptable_priority_fee_in_gwei: Some(this.max_acceptable_priority_fee_in_gwei), diff --git a/core/lib/protobuf_config/src/proto/config/base_token_adjuster.proto b/core/lib/protobuf_config/src/proto/config/base_token_adjuster.proto index 1132858bfa6f..396bd400c04b 100644 --- a/core/lib/protobuf_config/src/proto/config/base_token_adjuster.proto +++ b/core/lib/protobuf_config/src/proto/config/base_token_adjuster.proto @@ -13,4 +13,6 @@ message BaseTokenAdjuster { optional uint32 l1_tx_sending_max_attempts = 8; optional uint64 l1_tx_sending_sleep_ms = 9; optional bool halt_on_error = 10; + optional uint32 price_fetching_max_attempts = 11; + optional uint64 price_fetching_sleep_ms = 12; } diff --git a/core/node/base_token_adjuster/Cargo.toml b/core/node/base_token_adjuster/Cargo.toml index c21576e37327..3a0beb2ea137 100644 --- a/core/node/base_token_adjuster/Cargo.toml +++ b/core/node/base_token_adjuster/Cargo.toml @@ -19,7 +19,8 @@ zksync_external_price_api.workspace = true zksync_contracts.workspace = true zksync_eth_client.workspace = true zksync_node_fee_model.workspace = true - +zksync_utils.workspace = true +vise.workspace = true tokio = { workspace = true, features = ["time"] } anyhow.workspace = true diff --git a/core/node/base_token_adjuster/src/base_token_ratio_persister.rs b/core/node/base_token_adjuster/src/base_token_ratio_persister.rs index 41796cf2197a..15ecc9b5b798 100644 --- a/core/node/base_token_adjuster/src/base_token_ratio_persister.rs +++ b/core/node/base_token_adjuster/src/base_token_ratio_persister.rs @@ -13,6 +13,9 @@ use zksync_types::{ web3::{contract::Tokenize, BlockNumber}, Address, U256, }; +use zksync_utils::time::millis_since_epoch; + +use crate::metrics::{OperationResult, OperationResultLabels, METRICS}; #[derive(Debug, Clone)] pub struct BaseTokenRatioPersisterL1Params { @@ -82,47 +85,7 @@ impl BaseTokenRatioPersister { // TODO(PE-148): Consider shifting retry upon adding external API redundancy. let new_ratio = self.retry_fetch_ratio().await?; self.persist_ratio(new_ratio).await?; - - let Some(l1_params) = &self.l1_params else { - return Ok(()); - }; - - let max_attempts = self.config.l1_tx_sending_max_attempts; - let sleep_duration = self.config.l1_tx_sending_sleep_duration(); - let mut result: anyhow::Result<()> = Ok(()); - let mut prev_base_fee_per_gas: Option = None; - let mut prev_priority_fee_per_gas: Option = None; - - for attempt in 0..max_attempts { - let (base_fee_per_gas, priority_fee_per_gas) = - self.get_eth_fees(l1_params, prev_base_fee_per_gas, prev_priority_fee_per_gas); - - result = self - .send_ratio_to_l1(l1_params, new_ratio, base_fee_per_gas, priority_fee_per_gas) - .await; - if let Some(err) = result.as_ref().err() { - tracing::info!( - "Failed to update base token multiplier on L1, attempt {}, base_fee_per_gas {}, priority_fee_per_gas {}: {}", - attempt + 1, - base_fee_per_gas, - priority_fee_per_gas, - err - ); - tokio::time::sleep(sleep_duration).await; - prev_base_fee_per_gas = Some(base_fee_per_gas); - prev_priority_fee_per_gas = Some(priority_fee_per_gas); - } else { - tracing::info!( - "Updated base token multiplier on L1: numerator {}, denominator {}, base_fee_per_gas {}, priority_fee_per_gas {}", - new_ratio.numerator.get(), - new_ratio.denominator.get(), - base_fee_per_gas, - priority_fee_per_gas - ); - return result; - } - } - result + self.retry_update_ratio_on_l1(new_ratio).await } fn get_eth_fees( @@ -157,36 +120,119 @@ impl BaseTokenRatioPersister { (base_fee_per_gas, priority_fee_per_gas) } + async fn retry_update_ratio_on_l1(&self, new_ratio: BaseTokenAPIRatio) -> anyhow::Result<()> { + let Some(l1_params) = &self.l1_params else { + return Ok(()); + }; + + let start_time = millis_since_epoch(); + let max_attempts = self.config.l1_tx_sending_max_attempts; + let sleep_duration = self.config.l1_tx_sending_sleep_duration(); + let mut prev_base_fee_per_gas: Option = None; + let mut prev_priority_fee_per_gas: Option = None; + let mut last_error = None; + for attempt in 0..max_attempts { + let (base_fee_per_gas, priority_fee_per_gas) = + self.get_eth_fees(l1_params, prev_base_fee_per_gas, prev_priority_fee_per_gas); + + let result = self + .update_ratio_on_l1(l1_params, new_ratio, base_fee_per_gas, priority_fee_per_gas) + .await; + + match result { + Ok(x) => { + tracing::info!( + "Updated base token multiplier on L1: numerator {}, denominator {}, base_fee_per_gas {}, priority_fee_per_gas {}", + new_ratio.numerator.get(), + new_ratio.denominator.get(), + base_fee_per_gas, + priority_fee_per_gas + ); + METRICS + .l1_gas_used + .observe(x.unwrap_or(U256::zero()).low_u128() as f64); + METRICS.l1_update_latency[&OperationResultLabels { + result: OperationResult::Success, + attempts: attempt, + }] + .observe(Self::duration_from_millis( + millis_since_epoch() - start_time, + )); + return Ok(()); + } + Err(err) => { + tracing::info!( + "Failed to update base token multiplier on L1, attempt {}, base_fee_per_gas {}, priority_fee_per_gas {}: {}", + attempt, + base_fee_per_gas, + priority_fee_per_gas, + err + ); + tokio::time::sleep(sleep_duration).await; + prev_base_fee_per_gas = Some(base_fee_per_gas); + prev_priority_fee_per_gas = Some(priority_fee_per_gas); + last_error = Some(err) + } + } + } + METRICS.l1_update_latency[&OperationResultLabels { + result: OperationResult::Failure, + attempts: max_attempts, + }] + .observe(Self::duration_from_millis( + millis_since_epoch() - start_time, + )); + Err(last_error.unwrap_or(anyhow::format_err!( + "Failed to update base token multiplier on L1" + ))) + } + async fn retry_fetch_ratio(&self) -> anyhow::Result { - let sleep_duration = Duration::from_secs(1); - let max_retries = 5; - let mut attempts = 0; + let start_time = millis_since_epoch(); + let sleep_duration = self.config.price_fetching_sleep_duration(); + let max_retries = self.config.price_fetching_max_attempts; + let mut last_error = None; - loop { + for attempt in 0..max_retries { match self .price_api_client .fetch_ratio(self.base_token_address) .await { Ok(ratio) => { + METRICS.external_price_api_latency[&OperationResultLabels { + result: OperationResult::Success, + attempts: attempt, + }] + .observe(Self::duration_from_millis( + millis_since_epoch() - start_time, + )); return Ok(ratio); } - Err(err) if attempts < max_retries => { - attempts += 1; + Err(err) => { tracing::warn!( - "Attempt {}/{} to fetch ratio from coingecko failed with err: {}. Retrying...", - attempts, + "Attempt {}/{} to fetch ratio from external price api failed with err: {}. Retrying...", + attempt, max_retries, err ); + last_error = Some(err); sleep(sleep_duration).await; } - Err(err) => { - return Err(err) - .context("Failed to fetch base token ratio after multiple attempts"); - } } } + METRICS.external_price_api_latency[&OperationResultLabels { + result: OperationResult::Failure, + attempts: max_retries, + }] + .observe(Self::duration_from_millis( + millis_since_epoch() - start_time, + )); + + let error_message = "Failed to fetch base token ratio after multiple attempts"; + Err(last_error + .map(|x| x.context(error_message)) + .unwrap_or_else(|| anyhow::anyhow!(error_message))) } async fn persist_ratio(&self, api_ratio: BaseTokenAPIRatio) -> anyhow::Result { @@ -209,13 +255,13 @@ impl BaseTokenRatioPersister { Ok(id) } - async fn send_ratio_to_l1( + async fn update_ratio_on_l1( &self, l1_params: &BaseTokenRatioPersisterL1Params, api_ratio: BaseTokenAPIRatio, base_fee_per_gas: u64, priority_fee_per_gas: u64, - ) -> anyhow::Result<()> { + ) -> anyhow::Result> { let fn_set_token_multiplier = l1_params .chain_admin_contract .function("setTokenMultiplier") @@ -276,7 +322,7 @@ impl BaseTokenRatioPersister { .context("failed getting receipt for `setTokenMultiplier` transaction")?; if let Some(receipt) = maybe_receipt { if receipt.status == Some(1.into()) { - return Ok(()); + return Ok(receipt.gas_used); } return Err(anyhow::Error::msg(format!( "`setTokenMultiplier` transaction {:?} failed with status {:?}", @@ -293,4 +339,8 @@ impl BaseTokenRatioPersister { max_attempts ))) } + + fn duration_from_millis(millis: u128) -> Duration { + Duration::from_millis(millis as u64) + } } diff --git a/core/node/base_token_adjuster/src/lib.rs b/core/node/base_token_adjuster/src/lib.rs index 332fb5f47aab..d786b440f622 100644 --- a/core/node/base_token_adjuster/src/lib.rs +++ b/core/node/base_token_adjuster/src/lib.rs @@ -5,3 +5,4 @@ pub use self::{ mod base_token_ratio_persister; mod base_token_ratio_provider; +mod metrics; diff --git a/core/node/base_token_adjuster/src/metrics.rs b/core/node/base_token_adjuster/src/metrics.rs new file mode 100644 index 000000000000..8fb4ee999b58 --- /dev/null +++ b/core/node/base_token_adjuster/src/metrics.rs @@ -0,0 +1,34 @@ +use std::time::Duration; + +use vise::{Buckets, EncodeLabelSet, EncodeLabelValue, Family, Histogram, Metrics}; + +#[derive(Debug, Clone, Copy, PartialEq, Eq, Hash, EncodeLabelSet, EncodeLabelValue)] +#[metrics(label = "operation_result", rename_all = "snake_case")] +pub(super) enum OperationResult { + Success, + Failure, +} + +#[derive(Debug, Clone, Copy, PartialEq, Eq, Hash, EncodeLabelSet)] +pub(crate) struct OperationResultLabels { + pub result: OperationResult, + pub attempts: u32, +} + +/// Roughly exponential buckets for gas (10k – 50M). +const GAS_BUCKETS: Buckets = + Buckets::values(&[1e4, 2e4, 5e4, 1e5, 2e5, 5e5, 1e6, 2e6, 5e6, 1e7, 2e7, 5e7]); + +#[derive(Debug, Metrics)] +#[metrics(prefix = "snapshots_creator")] +pub(crate) struct BaseTokenAdjusterMetrics { + #[metrics(buckets = GAS_BUCKETS)] + pub l1_gas_used: Histogram, + #[metrics(buckets = Buckets::LATENCIES)] + pub external_price_api_latency: Family>, + #[metrics(buckets = Buckets::LATENCIES)] + pub l1_update_latency: Family>, +} + +#[vise::register] +pub(crate) static METRICS: vise::Global = vise::Global::new(); From 0b05f1171098e89933f629bc46fdd60366e0abae Mon Sep 17 00:00:00 2001 From: Ivan Schasny Date: Fri, 23 Aug 2024 10:35:15 +0100 Subject: [PATCH 2/9] small fix --- .../base_token_adjuster/src/base_token_ratio_persister.rs | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/core/node/base_token_adjuster/src/base_token_ratio_persister.rs b/core/node/base_token_adjuster/src/base_token_ratio_persister.rs index 15ecc9b5b798..5588cf75924a 100644 --- a/core/node/base_token_adjuster/src/base_token_ratio_persister.rs +++ b/core/node/base_token_adjuster/src/base_token_ratio_persister.rs @@ -182,9 +182,10 @@ impl BaseTokenRatioPersister { .observe(Self::duration_from_millis( millis_since_epoch() - start_time, )); - Err(last_error.unwrap_or(anyhow::format_err!( - "Failed to update base token multiplier on L1" - ))) + let error_message = "Failed to update base token multiplier on L1"; + Err(last_error + .map(|x| x.context(error_message)) + .unwrap_or_else(|| anyhow::anyhow!(error_message))) } async fn retry_fetch_ratio(&self) -> anyhow::Result { From d557bd5f38202953bb70731923659855f05ae7f3 Mon Sep 17 00:00:00 2001 From: Ivan Schasny Date: Fri, 23 Aug 2024 11:03:48 +0100 Subject: [PATCH 3/9] fix test --- core/lib/env_config/src/base_token_adjuster.rs | 8 ++++++++ 1 file changed, 8 insertions(+) diff --git a/core/lib/env_config/src/base_token_adjuster.rs b/core/lib/env_config/src/base_token_adjuster.rs index 67cdef9425cd..f94e9c8f92a2 100644 --- a/core/lib/env_config/src/base_token_adjuster.rs +++ b/core/lib/env_config/src/base_token_adjuster.rs @@ -26,6 +26,8 @@ mod tests { l1_receipt_checking_sleep_ms: 20_000, l1_tx_sending_max_attempts: 10, l1_tx_sending_sleep_ms: 30_000, + price_fetching_max_attempts: 20, + price_fetching_sleep_ms: 10_000, halt_on_error: true, } } @@ -41,6 +43,8 @@ mod tests { l1_receipt_checking_sleep_ms: 30_000, l1_tx_sending_max_attempts: 3, l1_tx_sending_sleep_ms: 30_000, + price_fetching_max_attempts: 3, + price_fetching_sleep_ms: 5_000, halt_on_error: false, } } @@ -58,6 +62,8 @@ mod tests { BASE_TOKEN_ADJUSTER_L1_RECEIPT_CHECKING_SLEEP_MS=20000 BASE_TOKEN_ADJUSTER_L1_TX_SENDING_MAX_ATTEMPTS=10 BASE_TOKEN_ADJUSTER_L1_TX_SENDING_SLEEP_MS=30000 + BASE_TOKEN_ADJUSTER_PRICE_FETCHING_MAX_ATTEMPTS=20 + BASE_TOKEN_ADJUSTER_PRICE_FETCHING_SLEEP_MS=10000 BASE_TOKEN_ADJUSTER_HALT_ON_ERROR=true "#; lock.set_env(config); @@ -79,6 +85,8 @@ mod tests { "BASE_TOKEN_ADJUSTER_L1_RECEIPT_CHECKING_SLEEP_MS", "BASE_TOKEN_ADJUSTER_L1_TX_SENDING_MAX_ATTEMPTS", "BASE_TOKEN_ADJUSTER_L1_TX_SENDING_SLEEP_MS", + "BASE_TOKEN_ADJUSTER_PRICE_FETCHING_MAX_ATTEMPTS", + "BASE_TOKEN_ADJUSTER_PRICE_FETCHING_SLEEP_MS", "BASE_TOKEN_ADJUSTER_HALT_ON_ERROR", ]); From cdc4790888f38e7f4d4903bf975bfbac8da81319 Mon Sep 17 00:00:00 2001 From: Ivan Schasny Date: Fri, 23 Aug 2024 11:25:46 +0100 Subject: [PATCH 4/9] test fix --- core/lib/protobuf_config/src/base_token_adjuster.rs | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/core/lib/protobuf_config/src/base_token_adjuster.rs b/core/lib/protobuf_config/src/base_token_adjuster.rs index 542cbfd6d698..951feac16533 100644 --- a/core/lib/protobuf_config/src/base_token_adjuster.rs +++ b/core/lib/protobuf_config/src/base_token_adjuster.rs @@ -31,10 +31,10 @@ impl ProtoRepr for proto::BaseTokenAdjuster { .l1_receipt_checking_max_attempts .unwrap_or(Self::Type::default_l1_receipt_checking_max_attempts()), price_fetching_sleep_ms: self - .l1_receipt_checking_sleep_ms + .price_fetching_sleep_ms .unwrap_or(Self::Type::default_price_fetching_sleep_ms()), price_fetching_max_attempts: self - .l1_receipt_checking_max_attempts + .price_fetching_max_attempts .unwrap_or(Self::Type::default_price_fetching_max_attempts()), l1_tx_sending_max_attempts: self .l1_tx_sending_max_attempts From 453185966b7e7ef4d67a3a0e33f42f3fd4a891fd Mon Sep 17 00:00:00 2001 From: Ivan Schasny Date: Fri, 23 Aug 2024 13:19:14 +0100 Subject: [PATCH 5/9] review comments --- .../src/base_token_ratio_persister.rs | 75 ++++++++----------- core/node/base_token_adjuster/src/metrics.rs | 10 +-- 2 files changed, 32 insertions(+), 53 deletions(-) diff --git a/core/node/base_token_adjuster/src/base_token_ratio_persister.rs b/core/node/base_token_adjuster/src/base_token_ratio_persister.rs index 5588cf75924a..3ff74e6873a5 100644 --- a/core/node/base_token_adjuster/src/base_token_ratio_persister.rs +++ b/core/node/base_token_adjuster/src/base_token_ratio_persister.rs @@ -1,5 +1,5 @@ -use std::{cmp::max, fmt::Debug, sync::Arc, time::Duration}; - +use std::time::Instant; +use std::{cmp::max, fmt::Debug, sync::Arc}; use anyhow::Context as _; use tokio::{sync::watch, time::sleep}; use zksync_config::configs::base_token_adjuster::BaseTokenAdjusterConfig; @@ -13,7 +13,6 @@ use zksync_types::{ web3::{contract::Tokenize, BlockNumber}, Address, U256, }; -use zksync_utils::time::millis_since_epoch; use crate::metrics::{OperationResult, OperationResultLabels, METRICS}; @@ -125,7 +124,6 @@ impl BaseTokenRatioPersister { return Ok(()); }; - let start_time = millis_since_epoch(); let max_attempts = self.config.l1_tx_sending_max_attempts; let sleep_duration = self.config.l1_tx_sending_sleep_duration(); let mut prev_base_fee_per_gas: Option = None; @@ -135,6 +133,7 @@ impl BaseTokenRatioPersister { let (base_fee_per_gas, priority_fee_per_gas) = self.get_eth_fees(l1_params, prev_base_fee_per_gas, prev_priority_fee_per_gas); + let start_time = Instant::now(); let result = self .update_ratio_on_l1(l1_params, new_ratio, base_fee_per_gas, priority_fee_per_gas) .await; @@ -142,32 +141,35 @@ impl BaseTokenRatioPersister { match result { Ok(x) => { tracing::info!( - "Updated base token multiplier on L1: numerator {}, denominator {}, base_fee_per_gas {}, priority_fee_per_gas {}", - new_ratio.numerator.get(), - new_ratio.denominator.get(), - base_fee_per_gas, - priority_fee_per_gas - ); + "Updated base token multiplier on L1: numerator {}, denominator {}, base_fee_per_gas {}, priority_fee_per_gas {}", + new_ratio.numerator.get(), + new_ratio.denominator.get(), + base_fee_per_gas, + priority_fee_per_gas + ); METRICS .l1_gas_used - .observe(x.unwrap_or(U256::zero()).low_u128() as f64); + .set(x.unwrap_or(U256::zero()).low_u128() as u64); METRICS.l1_update_latency[&OperationResultLabels { result: OperationResult::Success, - attempts: attempt, }] - .observe(Self::duration_from_millis( - millis_since_epoch() - start_time, - )); + .observe(Instant::now().duration_since(start_time)); + return Ok(()); } Err(err) => { tracing::info!( - "Failed to update base token multiplier on L1, attempt {}, base_fee_per_gas {}, priority_fee_per_gas {}: {}", - attempt, - base_fee_per_gas, - priority_fee_per_gas, - err - ); + "Failed to update base token multiplier on L1, attempt {}, base_fee_per_gas {}, priority_fee_per_gas {}: {}", + attempt, + base_fee_per_gas, + priority_fee_per_gas, + err + ); + METRICS.l1_update_latency[&OperationResultLabels { + result: OperationResult::Failure, + }] + .observe(Instant::now().duration_since(start_time)); + tokio::time::sleep(sleep_duration).await; prev_base_fee_per_gas = Some(base_fee_per_gas); prev_priority_fee_per_gas = Some(priority_fee_per_gas); @@ -175,13 +177,7 @@ impl BaseTokenRatioPersister { } } } - METRICS.l1_update_latency[&OperationResultLabels { - result: OperationResult::Failure, - attempts: max_attempts, - }] - .observe(Self::duration_from_millis( - millis_since_epoch() - start_time, - )); + let error_message = "Failed to update base token multiplier on L1"; Err(last_error .map(|x| x.context(error_message)) @@ -189,12 +185,12 @@ impl BaseTokenRatioPersister { } async fn retry_fetch_ratio(&self) -> anyhow::Result { - let start_time = millis_since_epoch(); let sleep_duration = self.config.price_fetching_sleep_duration(); let max_retries = self.config.price_fetching_max_attempts; let mut last_error = None; for attempt in 0..max_retries { + let start_time = Instant::now(); match self .price_api_client .fetch_ratio(self.base_token_address) @@ -203,11 +199,8 @@ impl BaseTokenRatioPersister { Ok(ratio) => { METRICS.external_price_api_latency[&OperationResultLabels { result: OperationResult::Success, - attempts: attempt, }] - .observe(Self::duration_from_millis( - millis_since_epoch() - start_time, - )); + .observe(Instant::now().duration_since(start_time)); return Ok(ratio); } Err(err) => { @@ -218,18 +211,14 @@ impl BaseTokenRatioPersister { err ); last_error = Some(err); + METRICS.external_price_api_latency[&OperationResultLabels { + result: OperationResult::Failure, + }] + .observe(Instant::now().duration_since(start_time)); sleep(sleep_duration).await; } } } - METRICS.external_price_api_latency[&OperationResultLabels { - result: OperationResult::Failure, - attempts: max_retries, - }] - .observe(Self::duration_from_millis( - millis_since_epoch() - start_time, - )); - let error_message = "Failed to fetch base token ratio after multiple attempts"; Err(last_error .map(|x| x.context(error_message)) @@ -340,8 +329,4 @@ impl BaseTokenRatioPersister { max_attempts ))) } - - fn duration_from_millis(millis: u128) -> Duration { - Duration::from_millis(millis as u64) - } } diff --git a/core/node/base_token_adjuster/src/metrics.rs b/core/node/base_token_adjuster/src/metrics.rs index 8fb4ee999b58..e6f6571adc1d 100644 --- a/core/node/base_token_adjuster/src/metrics.rs +++ b/core/node/base_token_adjuster/src/metrics.rs @@ -1,6 +1,6 @@ use std::time::Duration; -use vise::{Buckets, EncodeLabelSet, EncodeLabelValue, Family, Histogram, Metrics}; +use vise::{Buckets, EncodeLabelSet, EncodeLabelValue, Family, Gauge, Histogram, Metrics}; #[derive(Debug, Clone, Copy, PartialEq, Eq, Hash, EncodeLabelSet, EncodeLabelValue)] #[metrics(label = "operation_result", rename_all = "snake_case")] @@ -12,18 +12,12 @@ pub(super) enum OperationResult { #[derive(Debug, Clone, Copy, PartialEq, Eq, Hash, EncodeLabelSet)] pub(crate) struct OperationResultLabels { pub result: OperationResult, - pub attempts: u32, } -/// Roughly exponential buckets for gas (10k – 50M). -const GAS_BUCKETS: Buckets = - Buckets::values(&[1e4, 2e4, 5e4, 1e5, 2e5, 5e5, 1e6, 2e6, 5e6, 1e7, 2e7, 5e7]); - #[derive(Debug, Metrics)] #[metrics(prefix = "snapshots_creator")] pub(crate) struct BaseTokenAdjusterMetrics { - #[metrics(buckets = GAS_BUCKETS)] - pub l1_gas_used: Histogram, + pub l1_gas_used: Gauge, #[metrics(buckets = Buckets::LATENCIES)] pub external_price_api_latency: Family>, #[metrics(buckets = Buckets::LATENCIES)] From cd10507d3c9b89f82b6b67ec95ede24176578882 Mon Sep 17 00:00:00 2001 From: Ivan Schasny Date: Fri, 23 Aug 2024 13:19:23 +0100 Subject: [PATCH 6/9] review comments --- core/node/base_token_adjuster/src/base_token_ratio_persister.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/core/node/base_token_adjuster/src/base_token_ratio_persister.rs b/core/node/base_token_adjuster/src/base_token_ratio_persister.rs index 3ff74e6873a5..ce2cb82faeab 100644 --- a/core/node/base_token_adjuster/src/base_token_ratio_persister.rs +++ b/core/node/base_token_adjuster/src/base_token_ratio_persister.rs @@ -1,6 +1,6 @@ +use anyhow::Context as _; use std::time::Instant; use std::{cmp::max, fmt::Debug, sync::Arc}; -use anyhow::Context as _; use tokio::{sync::watch, time::sleep}; use zksync_config::configs::base_token_adjuster::BaseTokenAdjusterConfig; use zksync_dal::{ConnectionPool, Core, CoreDal}; From b63a8a7f8a9c26005409f1862095aa73ef4e1d45 Mon Sep 17 00:00:00 2001 From: Ivan Schasny Date: Fri, 23 Aug 2024 13:24:42 +0100 Subject: [PATCH 7/9] review comments --- .../node/base_token_adjuster/src/base_token_ratio_persister.rs | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/core/node/base_token_adjuster/src/base_token_ratio_persister.rs b/core/node/base_token_adjuster/src/base_token_ratio_persister.rs index ce2cb82faeab..bab11f2bf627 100644 --- a/core/node/base_token_adjuster/src/base_token_ratio_persister.rs +++ b/core/node/base_token_adjuster/src/base_token_ratio_persister.rs @@ -1,6 +1,5 @@ use anyhow::Context as _; -use std::time::Instant; -use std::{cmp::max, fmt::Debug, sync::Arc}; +use std::{cmp::max, fmt::Debug, sync::Arc, time::Instant}; use tokio::{sync::watch, time::sleep}; use zksync_config::configs::base_token_adjuster::BaseTokenAdjusterConfig; use zksync_dal::{ConnectionPool, Core, CoreDal}; From 5307e659e1fc0565a3902dad42fd87a5e0598192 Mon Sep 17 00:00:00 2001 From: Ivan Schasny Date: Fri, 23 Aug 2024 13:25:29 +0100 Subject: [PATCH 8/9] review comments --- .../node/base_token_adjuster/src/base_token_ratio_persister.rs | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/core/node/base_token_adjuster/src/base_token_ratio_persister.rs b/core/node/base_token_adjuster/src/base_token_ratio_persister.rs index bab11f2bf627..138a5d8fc232 100644 --- a/core/node/base_token_adjuster/src/base_token_ratio_persister.rs +++ b/core/node/base_token_adjuster/src/base_token_ratio_persister.rs @@ -1,5 +1,6 @@ -use anyhow::Context as _; use std::{cmp::max, fmt::Debug, sync::Arc, time::Instant}; + +use anyhow::Context as _; use tokio::{sync::watch, time::sleep}; use zksync_config::configs::base_token_adjuster::BaseTokenAdjusterConfig; use zksync_dal::{ConnectionPool, Core, CoreDal}; From 90170b6ea861898257eb10c76df27c1a9b364b06 Mon Sep 17 00:00:00 2001 From: Ivan Schasny Date: Fri, 23 Aug 2024 15:45:29 +0100 Subject: [PATCH 9/9] review comments --- .../base_token_adjuster/src/base_token_ratio_persister.rs | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/core/node/base_token_adjuster/src/base_token_ratio_persister.rs b/core/node/base_token_adjuster/src/base_token_ratio_persister.rs index 138a5d8fc232..12cd6233efbb 100644 --- a/core/node/base_token_adjuster/src/base_token_ratio_persister.rs +++ b/core/node/base_token_adjuster/src/base_token_ratio_persister.rs @@ -153,7 +153,7 @@ impl BaseTokenRatioPersister { METRICS.l1_update_latency[&OperationResultLabels { result: OperationResult::Success, }] - .observe(Instant::now().duration_since(start_time)); + .observe(start_time.elapsed()); return Ok(()); } @@ -168,7 +168,7 @@ impl BaseTokenRatioPersister { METRICS.l1_update_latency[&OperationResultLabels { result: OperationResult::Failure, }] - .observe(Instant::now().duration_since(start_time)); + .observe(start_time.elapsed()); tokio::time::sleep(sleep_duration).await; prev_base_fee_per_gas = Some(base_fee_per_gas); @@ -200,7 +200,7 @@ impl BaseTokenRatioPersister { METRICS.external_price_api_latency[&OperationResultLabels { result: OperationResult::Success, }] - .observe(Instant::now().duration_since(start_time)); + .observe(start_time.elapsed()); return Ok(ratio); } Err(err) => { @@ -214,7 +214,7 @@ impl BaseTokenRatioPersister { METRICS.external_price_api_latency[&OperationResultLabels { result: OperationResult::Failure, }] - .observe(Instant::now().duration_since(start_time)); + .observe(start_time.elapsed()); sleep(sleep_duration).await; } }