Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
31 commits
Select commit Hold shift + click to select a range
8e6dc0b
add namespace to profiling
rodrigo-o Nov 7, 2025
5b5e3d6
initial testing of instumentation
rodrigo-o Nov 10, 2025
042b266
remove rpc namespaced instrumentation from breakdown panels
rodrigo-o Nov 10, 2025
e873b85
initial rpc dashboards
rodrigo-o Nov 10, 2025
cc97128
made some organization changes in the dashboard
rodrigo-o Nov 10, 2025
14dbeaf
make rpc dashboard repeatable by instance
rodrigo-o Nov 10, 2025
01bab1e
Merge branch 'main' into rpc-instrumentation-and-panels
rodrigo-o Nov 11, 2025
6dc47b9
separate Engine API from RPC API in instrumentation
rodrigo-o Nov 11, 2025
d0885bb
change total sum by average in pie charts of rpc
rodrigo-o Nov 11, 2025
6f82153
move from increase to rate for calculating the avg
rodrigo-o Nov 11, 2025
1b6cefa
go without any increase or rate
rodrigo-o Nov 11, 2025
c7d20d6
rework panels for engine api
rodrigo-o Nov 11, 2025
fe92933
reworked the RPC api panels
rodrigo-o Nov 11, 2025
bc00add
Added instances to the rpc and engine panels
rodrigo-o Nov 11, 2025
86fccd8
remove unintended overrides
rodrigo-o Nov 11, 2025
5968fd3
remove intemediary doc
rodrigo-o Nov 12, 2025
f75a0ac
initial rework of the instrumentation to avoid complex observers in p…
rodrigo-o Nov 12, 2025
6c4a9f5
go back to use just call to avoid most of rpc.rs changes made
rodrigo-o Nov 12, 2025
024b3f7
Add namespace to profiling and explicitly set it up in the previous i…
rodrigo-o Nov 12, 2025
c51eeea
fixed an issue with the way namespace is send through #instrument
rodrigo-o Nov 12, 2025
35d9cbd
Merge branch 'main' into rpc-instrumentation-and-panels
rodrigo-o Nov 13, 2025
28ec41f
enhanced record_debug and remove magic namespacing given targets
rodrigo-o Nov 13, 2025
6e5b041
format
rodrigo-o Nov 13, 2025
f6a401b
apply suggestions
rodrigo-o Nov 13, 2025
cd1534d
missed suggestions
rodrigo-o Nov 13, 2025
2948d97
updated cargo lock for l2 quote-gen
rodrigo-o Nov 13, 2025
39bd789
remove Cow given that it was already cloning
rodrigo-o Nov 13, 2025
5b167ab
Add comment about why we use String instead of &'static str in the na…
rodrigo-o Nov 13, 2025
e890efa
limit the life of exetension to the let timer block
rodrigo-o Nov 14, 2025
bd95d31
modify 5m ranges to the actual range selected in some panels
rodrigo-o Nov 14, 2025
89f1a09
Merge branch 'main' into rpc-instrumentation-and-panels
rodrigo-o Nov 14, 2025
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions Cargo.lock

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

1 change: 1 addition & 0 deletions Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -60,6 +60,7 @@ ethrex-levm = { path = "./crates/vm/levm" }
ethrex-trie = { path = "./crates/common/trie" }
ethrex-rlp = { path = "./crates/common/rlp" }
ethrex-crypto = { path = "./crates/common/crypto" }
ethrex-metrics = { path = "./crates/blockchain/metrics" }
ethrex-l2 = { path = "./crates/l2" }
ethrex-l2-common = { path = "./crates/l2/common" }
ethrex-sdk = { path = "./crates/l2/sdk" }
Expand Down
21 changes: 18 additions & 3 deletions crates/blockchain/blockchain.rs
Original file line number Diff line number Diff line change
Expand Up @@ -180,7 +180,12 @@ impl Blockchain {
}

/// Executes a block withing a new vm instance and state
#[instrument(level = "trace", name = "Execute Block", skip_all)]
#[instrument(
level = "trace",
name = "Execute Block",
skip_all,
fields(namespace = "block_execution")
)]
fn execute_block_pipeline(
&self,
block: &Block,
Expand Down Expand Up @@ -280,7 +285,12 @@ impl Blockchain {
))
}

#[instrument(level = "trace", name = "Trie update", skip_all)]
#[instrument(
level = "trace",
name = "Trie update",
skip_all,
fields(namespace = "block_execution")
)]
fn handle_merkleization(
&self,
rx: Receiver<Vec<AccountUpdate>>,
Expand Down Expand Up @@ -772,7 +782,12 @@ impl Blockchain {
})
}

#[instrument(level = "trace", name = "Block DB update", skip_all)]
#[instrument(
level = "trace",
name = "Block DB update",
skip_all,
fields(namespace = "block_execution")
)]
pub fn store_block(
&self,
block: Block,
Expand Down
98 changes: 90 additions & 8 deletions crates/blockchain/metrics/profiling.rs
Original file line number Diff line number Diff line change
@@ -1,6 +1,10 @@
use prometheus::{Encoder, HistogramTimer, HistogramVec, TextEncoder, register_histogram_vec};
use std::sync::LazyLock;
use tracing::{Subscriber, span::Id};
use std::{future::Future, sync::LazyLock};
use tracing::{
Subscriber,
field::{Field, Visit},
span::{Attributes, Id},
};
use tracing_subscriber::{Layer, layer::Context, registry::LookupSpan};

use crate::MetricsError;
Expand All @@ -11,8 +15,8 @@ pub static METRICS_BLOCK_PROCESSING_PROFILE: LazyLock<HistogramVec> =
fn initialize_histogram_vec() -> HistogramVec {
register_histogram_vec!(
"function_duration_seconds",
"Histogram of the run time of the functions in block processing",
&["function_name"]
"Histogram of the run time of the functions in block processing and RPC handling",
&["namespace", "function_name"]
)
.unwrap()
}
Expand All @@ -25,19 +29,72 @@ pub struct FunctionProfilingLayer;
/// Wrapper around [`HistogramTimer`] to avoid conflicts with other layers
struct ProfileTimer(HistogramTimer);

/// Span extension storing the profiling namespace selected by instrumentation. This needs to
/// be a String instead of a &'static str because using the span macros we could recieve dynamically
/// generated names and can't rely on only string literals.
struct Namespace(String);

#[derive(Default)]
struct NamespaceVisitor {
namespace: Option<String>,
}

impl Visit for NamespaceVisitor {
fn record_str(&mut self, field: &Field, value: &str) {
if field.name() == "namespace" {
self.namespace = Some(value.to_owned());
}
}

fn record_debug(&mut self, field: &Field, value: &dyn std::fmt::Debug) {
if field.name() == "namespace" {
let rendered = format!("{value:?}");
let cleaned = rendered
.strip_prefix('"')
.and_then(|s| s.strip_suffix('"'))
.unwrap_or(&rendered);
self.namespace = Some(cleaned.to_owned());
}
}
}

impl<S> Layer<S> for FunctionProfilingLayer
where
S: Subscriber + for<'a> LookupSpan<'a>,
{
fn on_new_span(&self, attrs: &Attributes<'_>, id: &Id, ctx: Context<'_, S>) {
let mut visitor = NamespaceVisitor::default();
attrs.record(&mut visitor);

if let (Some(span), Some(namespace)) = (ctx.span(id), visitor.namespace) {
span.extensions_mut().insert(Namespace(namespace));
}
}

fn on_enter(&self, id: &Id, ctx: Context<'_, S>) {
if let Some(span) = ctx.span(id)
&& span.metadata().target().starts_with("ethrex")
{
let name = span.metadata().name();
let target = span.metadata().target();

// Skip RPC modules; RPC timing is recorded explicitly at the call sites.
if target.contains("::rpc") {
return;
}
let timer = {
let extensions = span.extensions();
let namespace = extensions
.get::<Namespace>()
.map(|ns| ns.0.as_str())
.unwrap_or("default");

let function_name = span.metadata().name();

METRICS_BLOCK_PROCESSING_PROFILE
.with_label_values(&[namespace, function_name])
.start_timer()
};

let timer = METRICS_BLOCK_PROCESSING_PROFILE
.with_label_values(&[name])
.start_timer();
// PERF: `extensions_mut` uses a Mutex internally (per span)
span.extensions_mut().insert(ProfileTimer(timer));
}
Expand All @@ -54,6 +111,31 @@ where
}
}

/// Records the duration of an async operation in the function profiling histogram.
///
/// This provides a lightweight alternative to the `#[instrument]` attribute when you need
/// manual control over timing instrumentation, such as in RPC handlers.
///
/// # Parameters
/// * `namespace` - Category for the metric (e.g., "rpc", "engine", "block_execution")
/// * `function_name` - Name identifier for the operation being timed
/// * `future` - The async operation to time
///
/// Use this function when you need to instrument an async operation for duration metrics,
/// but cannot or do not want to use the `#[instrument]` attribute (for example, in RPC handlers).
pub async fn record_async_duration<Fut, T>(namespace: &str, function_name: &str, future: Fut) -> T
where
Fut: Future<Output = T>,
{
let timer = METRICS_BLOCK_PROCESSING_PROFILE
.with_label_values(&[namespace, function_name])
.start_timer();

let output = future.await;
timer.observe_duration();
output
}

pub fn gather_profiling_metrics() -> Result<String, MetricsError> {
let encoder = TextEncoder::new();
let metric_families = prometheus::gather();
Expand Down
28 changes: 24 additions & 4 deletions crates/blockchain/vm.rs
Original file line number Diff line number Diff line change
Expand Up @@ -44,21 +44,36 @@ impl StoreVmDatabase {
}

impl VmDatabase for StoreVmDatabase {
#[instrument(level = "trace", name = "Account read", skip_all)]
#[instrument(
level = "trace",
name = "Account read",
skip_all,
fields(namespace = "block_execution")
)]
fn get_account_state(&self, address: Address) -> Result<Option<AccountState>, EvmError> {
self.store
.get_account_state_by_root(self.state_root, address)
.map_err(|e| EvmError::DB(e.to_string()))
}

#[instrument(level = "trace", name = "Storage read", skip_all)]
#[instrument(
level = "trace",
name = "Storage read",
skip_all,
fields(namespace = "block_execution")
)]
fn get_storage_slot(&self, address: Address, key: H256) -> Result<Option<U256>, EvmError> {
self.store
.get_storage_at_root(self.state_root, address, key)
.map_err(|e| EvmError::DB(e.to_string()))
}

#[instrument(level = "trace", name = "Block hash read", skip_all)]
#[instrument(
level = "trace",
name = "Block hash read",
skip_all,
fields(namespace = "block_execution")
)]
fn get_block_hash(&self, block_number: u64) -> Result<H256, EvmError> {
// Check if we have it cached
if let Some(block_hash) = self.block_hash_cache.get(&block_number) {
Expand Down Expand Up @@ -103,7 +118,12 @@ impl VmDatabase for StoreVmDatabase {
Ok(self.store.get_chain_config())
}

#[instrument(level = "trace", name = "Account code read", skip_all)]
#[instrument(
level = "trace",
name = "Account code read",
skip_all,
fields(namespace = "block_execution")
)]
fn get_account_code(&self, code_hash: H256) -> Result<Code, EvmError> {
if code_hash == *EMPTY_KECCACK_HASH {
return Ok(Code::default());
Expand Down
55 changes: 53 additions & 2 deletions crates/l2/tee/quote-gen/Cargo.lock

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

1 change: 1 addition & 0 deletions crates/networking/rpc/Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,7 @@ ethrex-common.workspace = true
ethrex-storage.workspace = true
ethrex-vm.workspace = true
ethrex-blockchain.workspace = true
ethrex-metrics.workspace = true
ethrex-crypto.workspace = true
ethrex-p2p = { workspace = true, features = ["test-utils"] }
ethrex-rlp.workspace = true
Expand Down
11 changes: 10 additions & 1 deletion crates/networking/rpc/rpc.rs
Original file line number Diff line number Diff line change
Expand Up @@ -55,6 +55,7 @@ use bytes::Bytes;
use ethrex_blockchain::Blockchain;
use ethrex_blockchain::error::ChainError;
use ethrex_common::types::Block;
use ethrex_metrics::profiling::record_async_duration;
use ethrex_p2p::peer_handler::PeerHandler;
use ethrex_p2p::sync_manager::SyncManager;
use ethrex_p2p::types::Node;
Expand Down Expand Up @@ -191,7 +192,15 @@ pub trait RpcHandler: Sized {

async fn call(req: &RpcRequest, context: RpcApiContext) -> Result<Value, RpcErr> {
let request = Self::parse(&req.params)?;
request.handle(context).await
let namespace = match req.namespace() {
Ok(RpcNamespace::Engine) => "engine",
_ => "rpc",
};

record_async_duration(namespace, req.method.as_str(), async move {
request.handle(context).await
})
Comment on lines +200 to +202
Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We might want to have this behind the metrics feature flag maybe? I'll take a look at how the rest of the instrumentation was working with the previous breakdown panels and in any case create an issue to follow-up on this.

.await
}

async fn handle(&self, context: RpcApiContext) -> Result<Value, RpcErr>;
Expand Down
7 changes: 6 additions & 1 deletion crates/vm/backends/mod.rs
Original file line number Diff line number Diff line change
Expand Up @@ -77,7 +77,12 @@ impl Evm {
LEVM::execute_block(block, &mut self.db, self.vm_type)
}

#[instrument(level = "trace", name = "Block execution", skip_all)]
#[instrument(
level = "trace",
name = "Block execution",
skip_all,
fields(namespace = "block_execution")
)]
pub fn execute_block_pipeline(
&mut self,
block: &Block,
Expand Down
Loading
Loading