diff --git a/crates/rbuilder-operator/src/flashbots_config.rs b/crates/rbuilder-operator/src/flashbots_config.rs index 2d24ac69b..ada000661 100644 --- a/crates/rbuilder-operator/src/flashbots_config.rs +++ b/crates/rbuilder-operator/src/flashbots_config.rs @@ -170,7 +170,10 @@ impl LiveBuilderConfig for FlashbotsConfig { handle_subsidise_block(bidding_service.clone(), params) })?; let live_builder = live_builder.with_extra_rpc(module); - let builders = create_builders(self.live_builders()?); + let builders = create_builders( + self.live_builders()?, + self.base_config.max_order_execution_duration_warning(), + ); Ok(live_builder.with_builders(builders)) } diff --git a/crates/rbuilder/src/bin/run-bundle-on-prefix.rs b/crates/rbuilder/src/bin/run-bundle-on-prefix.rs index 9b50694c5..01eb99b31 100644 --- a/crates/rbuilder/src/bin/run-bundle-on-prefix.rs +++ b/crates/rbuilder/src/bin/run-bundle-on-prefix.rs @@ -170,6 +170,7 @@ impl LandedBlockInfo { false, order_statistics, CancellationToken::new(), + None, )?) } } diff --git a/crates/rbuilder/src/building/builders/block_building_helper.rs b/crates/rbuilder/src/building/builders/block_building_helper.rs index 3acc5124d..87c268692 100644 --- a/crates/rbuilder/src/building/builders/block_building_helper.rs +++ b/crates/rbuilder/src/building/builders/block_building_helper.rs @@ -1,4 +1,4 @@ -use alloy_primitives::{utils::format_ether, U256}; +use alloy_primitives::{utils::format_ether, Address, TxHash, U256}; use reth_provider::StateProvider; use std::{ cmp::max, @@ -7,7 +7,7 @@ use std::{ }; use time::OffsetDateTime; use tokio_util::sync::CancellationToken; -use tracing::{debug, error, trace}; +use tracing::{debug, error, trace, warn}; use crate::{ building::{ @@ -21,7 +21,10 @@ use crate::{ telemetry::{self, add_block_fill_time, add_order_simulation_time}, utils::{check_block_hash_reader_health, elapsed_ms, HistoricalBlockError}, }; -use rbuilder_primitives::{order_statistics::OrderStatistics, SimValue, SimulatedOrder}; +use rbuilder_primitives::{ + order_statistics::OrderStatistics, SimValue, SimulatedOrder, + TransactionSignedEcRecoveredWithBlobs, +}; use super::Block; @@ -157,6 +160,10 @@ pub struct BlockBuildingHelperFromProvider< cancel_on_fatal_error: CancellationToken, finalize_adjustment_state: Option, + + /// If an order execution duration (commit_order) is greater than this, we will log a warning with some info about the order. + /// This probably should not be implemented here and should be a wrapper but this is simpler. + max_order_execution_duration_warning: Option, } #[derive(Debug, thiserror::Error)] @@ -209,6 +216,7 @@ impl BlockBuildingHelperFromProvider { discard_txs: bool, available_orders_statistics: OrderStatistics, cancel_on_fatal_error: CancellationToken, + max_order_execution_duration_warning: Option, ) -> Result { BlockBuildingHelperFromProvider::new_with_execution_tracer( built_block_id, @@ -220,6 +228,7 @@ impl BlockBuildingHelperFromProvider { available_orders_statistics, cancel_on_fatal_error, NullPartialBlockExecutionTracer {}, + max_order_execution_duration_warning, ) } } @@ -244,6 +253,7 @@ impl< available_orders_statistics: OrderStatistics, cancel_on_fatal_error: CancellationToken, partial_block_execution_tracer: PartialBlockExecutionTracerType, + max_order_execution_duration_warning: Option, ) -> Result { let last_committed_block = building_ctx.block() - 1; check_block_hash_reader_health(last_committed_block, &state_provider)?; @@ -280,6 +290,7 @@ impl< built_block_trace, cancel_on_fatal_error, finalize_adjustment_state: None, + max_order_execution_duration_warning, }) } @@ -464,6 +475,52 @@ impl< }; Ok(FinalizeBlockResult { block }) } + + fn trace_slow_order_execution( + &self, + order: &SimulatedOrder, + sim_time: Duration, + result: &Result, CriticalCommitOrderError>, + ) { + #[derive(Debug)] + #[allow(dead_code)] + struct TxInfo { + pub hash: TxHash, + pub signer: Address, + pub to: Option
, + } + impl From<&TransactionSignedEcRecoveredWithBlobs> for TxInfo { + fn from(tx: &TransactionSignedEcRecoveredWithBlobs) -> Self { + Self { + hash: tx.hash(), + signer: tx.signer(), + to: tx.to(), + } + } + } + impl TxInfo { + fn parse_order(order: &SimulatedOrder) -> Vec { + order + .order + .list_txs() + .iter() + .map(|(tx, _)| (*tx).into()) + .collect::>() + } + } + match result { + Ok(Ok(result)) => { + warn!(?sim_time,builder_name=self.builder_name,id = ?order.id(),tob_sim_value = ?order.sim_value,txs = ?TxInfo::parse_order(order), + space_used = ?result.space_used,coinbase_profit = ?result.coinbase_profit,inplace_sim = ?result.inplace_sim, "Slow order ok execution"); + } + Ok(Err(err)) => { + warn!(?err,?sim_time,builder_name=self.builder_name,id = ?order.id(),tob_sim_value = ?order.sim_value,txs = ?TxInfo::parse_order(order), "Slow order failed execution."); + } + Err(err) => { + warn!(?err,?sim_time,builder_name=self.builder_name,id = ?order.id(),tob_sim_value = ?order.sim_value,txs = ?TxInfo::parse_order(order), "Slow order critical execution error."); + } + } + } } impl< @@ -487,6 +544,13 @@ impl< result_filter, ); let sim_time = start.elapsed(); + if self + .max_order_execution_duration_warning + .is_some_and(|max_dur| sim_time > max_dur) + { + self.trace_slow_order_execution(order, sim_time, &result); + } + let (result, sim_ok) = match result { Ok(ok_result) => match ok_result { Ok(res) => { diff --git a/crates/rbuilder/src/building/builders/mod.rs b/crates/rbuilder/src/building/builders/mod.rs index fe7ca777c..11cd69e97 100644 --- a/crates/rbuilder/src/building/builders/mod.rs +++ b/crates/rbuilder/src/building/builders/mod.rs @@ -27,6 +27,7 @@ use std::{ atomic::{AtomicU64, Ordering}, Arc, }, + time::Duration, }; use tokio::sync::{ broadcast, @@ -91,6 +92,7 @@ pub struct LiveBuilderInput

{ pub cancel: CancellationToken, pub built_block_cache: Arc, pub built_block_id_source: Arc, + pub max_order_execution_duration_warning: Option, } /// Struct that helps reading new orders/cancellations diff --git a/crates/rbuilder/src/building/builders/ordering_builder.rs b/crates/rbuilder/src/building/builders/ordering_builder.rs index 441439926..f6f9f9770 100644 --- a/crates/rbuilder/src/building/builders/ordering_builder.rs +++ b/crates/rbuilder/src/building/builders/ordering_builder.rs @@ -116,6 +116,7 @@ pub fn run_ordering_builder( input.builder_name, input.ctx, config.clone(), + input.max_order_execution_duration_warning, input.built_block_cache, ); @@ -185,6 +186,7 @@ where input.builder_name, input.ctx.clone(), ordering_config, + None, Arc::new(BuiltBlockCache::new()), ); let mut block_builder = builder.build_block_with_execution_tracer( @@ -208,6 +210,8 @@ pub struct OrderingBuilderContext { builder_name: String, ctx: BlockBuildingContext, config: OrderingBuilderConfig, + /// See [BlockBuildingHelperFromProvider::max_order_execution_duration_warning] + max_order_execution_duration_warning: Option, // caches local_ctx: ThreadBlockBuildingContext, @@ -224,6 +228,7 @@ impl OrderingBuilderContext { builder_name: String, ctx: BlockBuildingContext, config: OrderingBuilderConfig, + max_order_execution_duration_warning: Option, built_block_cache: Arc, ) -> Self { Self { @@ -235,6 +240,7 @@ impl OrderingBuilderContext { failed_orders: HashSet::default(), order_attempts: HashMap::default(), built_block_cache, + max_order_execution_duration_warning, } } @@ -285,6 +291,7 @@ impl OrderingBuilderContext { block_orders.orders_statistics(), cancel_block, partial_block_execution_tracer, + self.max_order_execution_duration_warning, )?; self.fill_orders( &mut block_building_helper, @@ -449,15 +456,21 @@ impl OrderingBuilderContext { pub struct OrderingBuildingAlgorithm { config: OrderingBuilderConfig, name: String, + max_order_execution_duration_warning: Option, /// The ordering priority type used to sort simulated orders. order_priority: PhantomData, } impl OrderingBuildingAlgorithm { - pub fn new(config: OrderingBuilderConfig, name: String) -> Self { + pub fn new( + config: OrderingBuilderConfig, + max_order_execution_duration_warning: Option, + name: String, + ) -> Self { Self { config, name, + max_order_execution_duration_warning, order_priority: PhantomData, } } @@ -483,6 +496,7 @@ where cancel: input.cancel, built_block_cache: input.built_block_cache, built_block_id_source: input.built_block_id_source, + max_order_execution_duration_warning: self.max_order_execution_duration_warning, }; run_ordering_builder::(live_input, &self.config); } diff --git a/crates/rbuilder/src/building/builders/parallel_builder/block_building_result_assembler.rs b/crates/rbuilder/src/building/builders/parallel_builder/block_building_result_assembler.rs index 7feade20c..78c5e2f78 100644 --- a/crates/rbuilder/src/building/builders/parallel_builder/block_building_result_assembler.rs +++ b/crates/rbuilder/src/building/builders/parallel_builder/block_building_result_assembler.rs @@ -5,7 +5,10 @@ use super::{ use ahash::HashMap; use alloy_primitives::utils::format_ether; use reth_provider::StateProvider; -use std::{sync::Arc, time::Instant}; +use std::{ + sync::Arc, + time::{Duration, Instant}, +}; use time::OffsetDateTime; use tokio_util::sync::CancellationToken; use tracing::{info_span, trace}; @@ -39,6 +42,7 @@ pub struct BlockBuildingResultAssembler { run_id: u64, last_version: Option, built_block_id_source: Arc, + max_order_execution_duration_warning: Option, } impl BlockBuildingResultAssembler { @@ -60,6 +64,7 @@ impl BlockBuildingResultAssembler { builder_name: String, sink: Option, built_block_id_source: Arc, + max_order_execution_duration_warning: Option, ) -> Self { Self { state, @@ -73,6 +78,7 @@ impl BlockBuildingResultAssembler { run_id: 0, last_version: None, built_block_id_source, + max_order_execution_duration_warning, } } @@ -189,6 +195,7 @@ impl BlockBuildingResultAssembler { self.discard_txs, OrderStatistics::default(), self.cancellation_token.clone(), + self.max_order_execution_duration_warning, )?; block_building_helper.set_trace_orders_closed_at(orders_closed_at); @@ -263,6 +270,7 @@ impl BlockBuildingResultAssembler { self.discard_txs, OrderStatistics::default(), CancellationToken::new(), + self.max_order_execution_duration_warning, )?; block_building_helper.set_trace_orders_closed_at(orders_closed_at); diff --git a/crates/rbuilder/src/building/builders/parallel_builder/mod.rs b/crates/rbuilder/src/building/builders/parallel_builder/mod.rs index 0a39d940b..0ad031e83 100644 --- a/crates/rbuilder/src/building/builders/parallel_builder/mod.rs +++ b/crates/rbuilder/src/building/builders/parallel_builder/mod.rs @@ -22,7 +22,7 @@ use simulation_cache::SharedSimulationCache; use std::{ sync::{mpsc as std_mpsc, Arc}, thread, - time::Instant, + time::{Duration, Instant}, }; use task::*; use time::OffsetDateTime; @@ -134,6 +134,7 @@ where input.builder_name.clone(), Some(input.sink.clone()), input.built_block_id_source.clone(), + input.max_order_execution_duration_warning, ); let order_intake_consumer = OrderIntakeStore::new(input.input); @@ -352,6 +353,7 @@ where String::from("backtest_builder"), None, Arc::new(BuiltBlockIdSource::new()), + None, ); let assembler_duration = assembler_start.elapsed(); @@ -394,12 +396,21 @@ where #[derive(Debug)] pub struct ParallelBuildingAlgorithm { config: ParallelBuilderConfig, + max_order_execution_duration_warning: Option, name: String, } impl ParallelBuildingAlgorithm { - pub fn new(config: ParallelBuilderConfig, name: String) -> Self { - Self { config, name } + pub fn new( + config: ParallelBuilderConfig, + max_order_execution_duration_warning: Option, + name: String, + ) -> Self { + Self { + config, + max_order_execution_duration_warning, + name, + } } } @@ -421,6 +432,7 @@ where cancel: input.cancel, built_block_cache: input.built_block_cache, built_block_id_source: input.built_block_id_source, + max_order_execution_duration_warning: self.max_order_execution_duration_warning, }; run_parallel_builder(live_input, &self.config); } diff --git a/crates/rbuilder/src/live_builder/base_config.rs b/crates/rbuilder/src/live_builder/base_config.rs index 1a41e84ca..733121e74 100644 --- a/crates/rbuilder/src/live_builder/base_config.rs +++ b/crates/rbuilder/src/live_builder/base_config.rs @@ -140,6 +140,9 @@ pub struct BaseConfig { /// List of `builders` to be used for live building pub live_builders: Vec, + /// See [BlockBuildingHelperFromProvider::max_order_execution_duration_warning] + pub max_order_execution_duration_warning_us: Option, + /// Config for IPC state provider pub ipc_provider: Option, @@ -466,6 +469,10 @@ impl BaseConfig { Ok(path_expanded.parse()?) } + pub fn max_order_execution_duration_warning(&self) -> Option { + self.max_order_execution_duration_warning_us + .map(Duration::from_micros) + } } pub const DEFAULT_CL_NODE_URL: &str = "http://127.0.0.1:3500"; @@ -530,6 +537,7 @@ impl Default for BaseConfig { orderflow_tracing_store_path: None, orderflow_tracing_max_blocks: 0, system_recipient_allowlist: Vec::new(), + max_order_execution_duration_warning_us: None, } } } diff --git a/crates/rbuilder/src/live_builder/config.rs b/crates/rbuilder/src/live_builder/config.rs index 83e8ae925..7ca1bc2a2 100644 --- a/crates/rbuilder/src/live_builder/config.rs +++ b/crates/rbuilder/src/live_builder/config.rs @@ -508,7 +508,10 @@ impl LiveBuilderConfig for Config { cancellation_token, ) .await?; - let builders = create_builders(self.live_builders()?); + let builders = create_builders( + self.live_builders()?, + self.base_config.max_order_execution_duration_warning(), + ); Ok(live_builder.with_builders(builders)) } @@ -752,33 +755,55 @@ pub fn coinbase_signer_from_secret_key(secret_key: &str) -> eyre::Result Ok(Signer::try_from_secret(secret_key)?) } -pub fn create_builders

(configs: Vec) -> Vec>> +pub fn create_builders

( + configs: Vec, + max_order_execution_duration_warning: Option, +) -> Vec>> where P: StateProviderFactory + Clone + 'static, { - configs.into_iter().map(|cfg| create_builder(cfg)).collect() + configs + .into_iter() + .map(|cfg| create_builder(cfg, max_order_execution_duration_warning)) + .collect() } -fn create_builder

(cfg: BuilderConfig) -> Arc> +fn create_builder

( + cfg: BuilderConfig, + max_order_execution_duration_warning: Option, +) -> Arc> where P: StateProviderFactory + Clone + 'static, { match cfg.builder { SpecificBuilderConfig::OrderingBuilder(order_cfg) => { if order_cfg.ignore_mempool_profit_on_bundles { - create_ordering_builder::(order_cfg, cfg.name) + create_ordering_builder::( + order_cfg, + max_order_execution_duration_warning, + cfg.name, + ) } else { - create_ordering_builder::(order_cfg, cfg.name) + create_ordering_builder::( + order_cfg, + max_order_execution_duration_warning, + cfg.name, + ) } } SpecificBuilderConfig::ParallelBuilder(parallel_cfg) => { - Arc::new(ParallelBuildingAlgorithm::new(parallel_cfg, cfg.name)) + Arc::new(ParallelBuildingAlgorithm::new( + parallel_cfg, + max_order_execution_duration_warning, + cfg.name, + )) } } } fn create_ordering_builder( cfg: OrderingBuilderConfig, + max_order_execution_duration_warning: Option, name: String, ) -> Arc> where @@ -787,19 +812,33 @@ where match cfg.sorting { Sorting::MevGasPrice => Arc::new(OrderingBuildingAlgorithm::< OrderMevGasPricePriority, - >::new(cfg, name)), + >::new( + cfg, max_order_execution_duration_warning, name + )), Sorting::MaxProfit => Arc::new(OrderingBuildingAlgorithm::< OrderMaxProfitPriority, - >::new(cfg, name)), + >::new( + cfg, max_order_execution_duration_warning, name + )), Sorting::TypeMaxProfit => Arc::new(OrderingBuildingAlgorithm::< OrderTypePriority, - >::new(cfg, name)), - Sorting::LengthThreeMaxProfit => Arc::new(OrderingBuildingAlgorithm::< - OrderLengthThreeMaxProfitPriority, - >::new(cfg, name)), - Sorting::LengthThreeMevGasPrice => Arc::new(OrderingBuildingAlgorithm::< - OrderLengthThreeMevGasPricePriority, - >::new(cfg, name)), + >::new( + cfg, max_order_execution_duration_warning, name + )), + Sorting::LengthThreeMaxProfit => { + Arc::new(OrderingBuildingAlgorithm::< + OrderLengthThreeMaxProfitPriority, + >::new( + cfg, max_order_execution_duration_warning, name + )) + } + Sorting::LengthThreeMevGasPrice => { + Arc::new(OrderingBuildingAlgorithm::< + OrderLengthThreeMevGasPricePriority, + >::new( + cfg, max_order_execution_duration_warning, name + )) + } } } diff --git a/docs/CONFIG.md b/docs/CONFIG.md index e6656d7c0..71ff7efa0 100644 --- a/docs/CONFIG.md +++ b/docs/CONFIG.md @@ -81,6 +81,7 @@ Every field has a default if omitted. |cl_node_url|vec[env/stirng]| Array if urls to CL clients to get the new payload events|["http://127.0.0.1:3500"] |genesis_fork_version|optional string|Genesis fork version for the chain. If not provided it will be fetched from the beacon client.|None| |relay_bid_scrapers||See [bid scraper publishers](../crates/bid-scraper/README.md) |Empty| +|max_order_execution_duration_warning_us|optional u64| If set, while building a block if an order execution duration is greater than this, we will log a warning with some info about the order.|None| ## Building algorithms rbuilder can multiple building algorithms and each algorithm can be instantiated multiple times with it's own set of parameters each time. Each instantiated algorithm starts with: