diff --git a/Cargo.lock b/Cargo.lock index 2ca77cb..a1fa8a6 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1951,6 +1951,7 @@ version = "0.2.0" dependencies = [ "alloy", "axum 0.7.9", + "chrono", "eyre", "init4-bin-base", "openssl", diff --git a/Cargo.toml b/Cargo.toml index 096621b..a10a472 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -54,6 +54,7 @@ openssl = { version = "0.10", features = ["vendored"] } reqwest = { version = "0.11.24", features = ["blocking", "json"] } serde_json = "1.0" tokio = { version = "1.36.0", features = ["full", "macros", "rt-multi-thread"] } +chrono = "0.4.40" tokio-stream = "0.1.17" url = "2.5.4" diff --git a/src/tasks/block/sim.rs b/src/tasks/block/sim.rs index f9775e0..c1fb8b4 100644 --- a/src/tasks/block/sim.rs +++ b/src/tasks/block/sim.rs @@ -20,7 +20,7 @@ use tokio::{ }, task::JoinHandle, }; -use tracing::info; +use tracing::{Instrument, info, instrument}; use trevm::revm::{ context::BlockEnv, database::{AlloyDB, WrapDatabaseAsync}, @@ -92,6 +92,11 @@ impl Simulator { /// # Returns /// /// A `Result` containing the built block or an error. + #[instrument(skip_all, fields( + block_number = block_env.number, + tx_count = sim_items.len(), + millis_to_deadline = finish_by.duration_since(Instant::now()).as_millis() + ))] pub async fn handle_build( &self, constants: SignetSystemConstants, @@ -99,7 +104,6 @@ impl Simulator { finish_by: Instant, block_env: BlockEnv, ) -> eyre::Result { - debug!(block_number = block_env.number, tx_count = sim_items.len(), "starting block build",); let concurrency_limit = self.config.concurrency_limit(); // NB: Build AlloyDB from the previous block number's state, since block_env maps to the in-progress block @@ -116,7 +120,7 @@ impl Simulator { self.config.rollup_block_gas_limit, ); - let built_block = block_build.build().await; + let built_block = block_build.build().in_current_span().await; debug!( tx_count = built_block.tx_count(), block_number = built_block.block_number(), @@ -205,8 +209,9 @@ impl Simulator { /// /// # Returns /// - /// An `Instant` representing the simulation deadline, as calculated by determining - /// the time left in the current slot and adding that to the current timestamp in UNIX seconds. + /// An `Instant` representing the simulation deadline, as calculated by + /// determining the time left in the current slot and adding that to the + /// current timestamp in UNIX seconds. pub fn calculate_deadline(&self) -> Instant { // Get the current timepoint within the slot. let timepoint = @@ -214,12 +219,10 @@ impl Simulator { // We have the timepoint in seconds into the slot. To find out what's // remaining, we need to subtract it from the slot duration - let remaining = self.slot_calculator().slot_duration() - timepoint; - - // We add a 2500 ms buffer to account for sequencer stopping signing. - let deadline = - Instant::now() + Duration::from_secs(remaining) - Duration::from_millis(2500); + // we also subtract 3 seconds to account for the sequencer stopping signing. + let remaining = (self.slot_calculator().slot_duration() - timepoint).saturating_sub(3); + let deadline = Instant::now() + Duration::from_secs(remaining); deadline.max(Instant::now()) } diff --git a/src/tasks/submit/task.rs b/src/tasks/submit/task.rs index 7bb9993..365e843 100644 --- a/src/tasks/submit/task.rs +++ b/src/tasks/submit/task.rs @@ -37,6 +37,21 @@ macro_rules! spawn_provider_send { }; } +macro_rules! check_slot_still_valid { + ($self:expr, $initial_slot:expr) => { + if !$self.slot_still_valid($initial_slot) { + debug!( + current_slot = + $self.config.slot_calculator.current_slot().expect("host chain has started"), + initial_slot = $initial_slot, + "slot changed before submission - skipping block" + ); + counter!("builder.slot_missed").increment(1); + return Ok(ControlFlow::Skip); + } + }; +} + /// Control flow for transaction submission. #[derive(Debug, Copy, Clone, PartialEq, Eq)] pub enum ControlFlow { @@ -130,18 +145,9 @@ impl SubmitTask { retry_limit: usize, ) -> eyre::Result { let submitting_start_time = Instant::now(); - let now = utils::now(); let (expected_slot, window) = self.get_expected_slot_and_window(); - debug!( - expected_slot, - start = window.start, - end = window.end, - now, - "calculating target slot window" - ); - let mut req = bumpable.req().clone(); // Retry loop @@ -151,27 +157,26 @@ impl SubmitTask { "SubmitTask::retrying_send", retries = bumpable.bump_count(), nonce = bumpable.req().nonce, + expected_slot, + start = window.start, + end = window.end, + unix_now = utils::now(), ); - let inbound_result = match self.send_transaction(req).instrument(span.clone()).await { - Ok(control_flow) => control_flow, - Err(error) => { - if let Some(value) = self.slot_still_valid(expected_slot) { - return value; - } - // Log error and retry - error!(%error, "error handling inbound block"); - ControlFlow::Retry - } - }; + // Check at the top of the loop if the slot is still valid. This + // will prevent unnecessary retries if the slot has changed. + check_slot_still_valid!(self, expected_slot); - let guard = span.entered(); + let inbound_result = self + .send_transaction(req) + .instrument(span.clone()) + .await + .inspect_err(|e| error!(error = %e, "sending transaction")) + .unwrap_or(ControlFlow::Retry); + let guard = span.entered(); match inbound_result { ControlFlow::Retry => { - if let Some(value) = self.slot_still_valid(expected_slot) { - return value; - } // bump the req req = bumpable.bumped(); if bumpable.bump_count() > retry_limit { @@ -221,17 +226,8 @@ impl SubmitTask { } /// Checks if a slot is still valid during submission retries. - fn slot_still_valid(&self, initial_slot: usize) -> Option> { - let current_slot = - self.config.slot_calculator.current_slot().expect("host chain has started"); - if current_slot != initial_slot { - // If the slot has changed, skip the block - debug!(current_slot, initial_slot, "slot changed before submission - skipping block"); - counter!("builder.slot_missed").increment(1); - return Some(Ok(ControlFlow::Skip)); - } - debug!(current_slot, "slot still valid - continuing submission"); - None + fn slot_still_valid(&self, initial_slot: usize) -> bool { + initial_slot == self.config.slot_calculator.current_slot().expect("host chain has started") } /// Task future for the submit task. This function runs the main loop of the task. diff --git a/src/utils.rs b/src/utils.rs index 53a8414..4201bf3 100644 --- a/src/utils.rs +++ b/src/utils.rs @@ -6,12 +6,10 @@ use alloy::{ }; use signet_sim::BuiltBlock; use signet_zenith::BundleHelper::FillPermit2; -use std::time::UNIX_EPOCH; /// Returns the current timestamp in seconds since the UNIX epoch. pub(crate) fn now() -> u64 { - let now = std::time::SystemTime::now(); - now.duration_since(UNIX_EPOCH).unwrap().as_secs() + chrono::Utc::now().timestamp() as u64 } // This function converts &[SignedFill] into [FillPermit2]