Skip to content

Commit

Permalink
chore(logging): Add tracing to validation code for debugging / perfor…
Browse files Browse the repository at this point in the history 
…mance evaluation (#20)

* Add logging in the api endpoint including tracing performance

* Use declarative macro for valdiation step tracing

* use nightly toolchain in ci

* Move validation to inner function and add top level success / failure log

* Adjust log level for consistency

* Use function instead of macro

* Factor valdiation code out to struct

* Cargo fmt

* Move state root validation to separate function to measure time separately

* Cargo fmt

* Clippy

* Factor out validation logic to separate file

* Add Request ids to debug logs in gas limit check

* Cargo fmt

* Clippy

* Clippy
  • Loading branch information
@ckoopmann
ckoopmann authored Dec 13, 2023
1 parent cc5e2ff commit 6cd0468
Show file tree
Hide file tree
Showing 7 changed files with 376 additions and 224 deletions.
10 changes: 5 additions & 5 deletions .github/workflows/check-lint-test.yaml
View file
Original file line number Diff line number Diff line change
Expand Up @@ -21,21 +21,21 @@ jobs:
- name: Checkout sources
uses: actions/checkout@v3
- name: Install toolchain
uses: dtolnay/rust-toolchain@stable
uses: dtolnay/rust-toolchain@nightly
with:
components: rustfmt, clippy
- uses: Swatinem/rust-cache@v2
with:
cache-on-failure: true

- name: cargo check
run: cargo check --all --all-features --benches --tests
run: cargo +nightly check --all --all-features --benches --tests

- name: cargo fmt
run: cargo fmt --all --check
run: cargo +nightly fmt --all --check

- name: cargo clippy
run: cargo clippy --all --all-features --benches --tests
run: cargo +nightly clippy --all --all-features --benches --tests

- name: cargo test
run: cargo test
run: cargo +nightly test
6 changes: 4 additions & 2 deletions Cargo.lock
View file

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

2 changes: 2 additions & 0 deletions Cargo.toml
View file
Original file line number Diff line number Diff line change
Expand Up @@ -25,10 +25,12 @@ hex = "0.4.3"
jsonrpsee = "0.20.1"
reth = { git = "https://github.com/paradigmxyz/reth", rev = "c1d7d2bde398bcf410c7e2df13fd7151fc2a58b9" }
reth-db = { features = ["test-utils"], git = "https://github.com/paradigmxyz/reth", rev = "c1d7d2bde398bcf410c7e2df13fd7151fc2a58b9"}
reth-tracing = { git = "https://github.com/paradigmxyz/reth", rev = "c1d7d2bde398bcf410c7e2df13fd7151fc2a58b9"}
secp256k1 = { version = "0.28.0", features = ["rand-std"] }
serde = "1.0.188"
serde_json = "1.0.107"
serde_with = "3.3.0"
uuid = "1.6.1"

[dev-dependencies]
tokio = "1.32.0"
217 changes: 7 additions & 210 deletions src/rpc/mod.rs
View file
Original file line number Diff line number Diff line change
@@ -1,31 +1,20 @@
use async_trait::async_trait;
use jsonrpsee::{core::RpcResult, proc_macros::rpc};

use reth::consensus_common::validation::full_validation;
use reth::primitives::{
revm_primitives::AccountInfo, Address, ChainSpec, Receipts, SealedBlock, TransactionSigned,
B256, U256,
};
use crate::ValidationApi;
use reth::providers::{
AccountReader, BlockExecutor, BlockReaderIdExt, BundleStateWithReceipts, ChainSpecProvider,
HeaderProvider, StateProviderFactory, WithdrawalsProvider,
AccountReader, BlockReaderIdExt, ChainSpecProvider, HeaderProvider, StateProviderFactory,
WithdrawalsProvider,
};
use reth::revm::{database::StateProviderDatabase, db::BundleState, processor::EVMProcessor};
use reth::rpc::compat::engine::payload::try_into_sealed_block;
use reth::rpc::result::ToRpcResult;

use std::sync::Arc;

use crate::ValidationApi;

mod types;
pub use types::*;

mod result;
use result::internal_rpc_err;

mod utils;
use utils::*;
mod validation;
use validation::ValidationRequest;

/// trait interface for a custom rpc namespace: `validation`
///
Expand Down Expand Up @@ -61,172 +50,6 @@ where
let inner = Arc::new(ValidationApiInner { provider });
Self { inner }
}

fn execute_and_verify_block(
&self,
block: &SealedBlock,
chain_spec: Arc<ChainSpec>,
) -> RpcResult<BundleStateWithReceipts> {
let state_provider = self.provider().latest().to_rpc_result()?;

let mut executor =
EVMProcessor::new_with_db(chain_spec, StateProviderDatabase::new(&state_provider));

let unsealed_block = block.clone().unseal();
// Note: Setting total difficulty to U256::MAX makes this incompatible with pre merge POW
// blocks
// TODO: Check what exactly the "senders" argument is and if we can set it to None here
executor
.execute_and_verify_receipt(&unsealed_block, U256::MAX, None)
.map_err(|e| internal_rpc_err(format!("Error executing transactions: {:}", e)))?;

let state = executor.take_output_state();

let state_root = state_provider
.state_root(&state)
.map_err(|e| internal_rpc_err(format!("Error computing state root: {e:?}")))?;
if state_root != block.state_root {
return Err(internal_rpc_err(format!(
"State root mismatch. Expected: {}. Received: {}",
state_root, block.state_root
)));
}

Ok(state)
}

fn check_proposer_payment(
&self,
block: &SealedBlock,
state: &BundleStateWithReceipts,
expected_payment: &U256,
fee_recipient: &Address,
) -> RpcResult<()> {
if check_proposer_balance_change(state.state(), fee_recipient, expected_payment) {
return Ok(());
}

check_proposer_payment_in_last_transaction(
&block.body,
state.receipts(),
fee_recipient,
expected_payment,
)
}

fn check_gas_limit(
&self,
parent_hash: &B256,
registered_gas_limit: u64,
block_gas_limit: u64,
) -> RpcResult<()> {
let parent =
self.provider()
.header(parent_hash)
.to_rpc_result()?
.ok_or(internal_rpc_err(format!(
"Parent block with hash {} not found",
parent_hash
)))?;

// Prysm has a bug where it registers validators with a desired gas limit
// of 0. Some builders treat these as desiring gas limit 30_000_000. As a
// workaround, whenever the desired gas limit is 0, we accept both the
// limit as calculated with a desired limit of 0, and builders which fall
// back to calculating with the default 30_000_000.
// TODO: Review if we still need this
if registered_gas_limit == 0
&& block_gas_limit == calc_gas_limit(parent.gas_limit, 30_000_000)
{
return Ok(());
}
let calculated_gas_limit = calc_gas_limit(parent.gas_limit, registered_gas_limit);
if calculated_gas_limit == block_gas_limit {
return Ok(());
}
Err(internal_rpc_err(format!(
"Incorrect gas limit set, expected: {}, got: {}",
calculated_gas_limit, block_gas_limit
)))
}
}

fn check_proposer_payment_in_last_transaction(
transactions: &Vec<TransactionSigned>,
receipts: &Receipts,
fee_recipient: &Address,
expected_payment: &U256,
) -> RpcResult<()> {
if receipts.is_empty() || receipts[0].is_empty() {
return Err(internal_rpc_err(
"No receipts in block to verify proposer payment",
));
}
let receipts = &receipts[0];

let num_transactions = transactions.len();
if num_transactions == 0 {
return Err(internal_rpc_err(
"No transactions in block to verify proposer payment",
));
}
if num_transactions != receipts.len() {
return Err(internal_rpc_err(format!(
"Number of receipts ({}) does not match number of transactions ({})",
receipts.len(),
num_transactions
)));
}

let proposer_payment_tx = transactions[num_transactions - 1].clone();
if proposer_payment_tx.to() != Some(*fee_recipient) {
return Err(internal_rpc_err(format!(
"Proposer payment tx to address {:?} does not match fee recipient {}",
proposer_payment_tx.to(),
fee_recipient
)));
}

if proposer_payment_tx.value() != *expected_payment {
return Err(internal_rpc_err(format!(
"Proposer payment tx value {} does not match expected payment {}",
proposer_payment_tx.value(),
expected_payment
)));
}

let proposer_payment_receipt = receipts[num_transactions - 1]
.clone()
.ok_or_else(|| internal_rpc_err("Proposer payment receipt not found in block receipts"))?;
if !proposer_payment_receipt.success {
return Err(internal_rpc_err(format!(
"Proposer payment tx failed: {:?}",
proposer_payment_receipt
)));
}

Ok(())
}

fn check_proposer_balance_change(
output_state: &BundleState,
fee_recipient: &Address,
expected_payment: &U256,
) -> bool {
let fee_receiver_account_state = match output_state.state.get(fee_recipient) {
Some(account) => account,
None => return false,
};
let fee_receiver_account_after = match fee_receiver_account_state.info.clone() {
Some(account) => account,
None => return false,
};
let fee_receiver_account_before = match fee_receiver_account_state.original_info.clone() {
Some(account) => account,
None => AccountInfo::default(), // TODO: In tests with the MockProvider this was None by default, check if this fallback is needed in production
};

fee_receiver_account_after.balance >= (fee_receiver_account_before.balance + expected_payment)
}

#[async_trait]
Expand All @@ -245,34 +68,8 @@ where
&self,
request_body: ValidationRequestBody,
) -> RpcResult<()> {
let block = try_into_sealed_block(request_body.execution_payload.clone().into(), None)
.to_rpc_result()?;
let chain_spec = self.provider().chain_spec();
self.check_gas_limit(
&block.parent_hash,
request_body.registered_gas_limit,
block.gas_limit,
)?;

compare_values(
"ParentHash",
request_body.message.parent_hash,
block.parent_hash,
)?;
compare_values("BlockHash", request_body.message.block_hash, block.hash())?;
compare_values("GasLimit", request_body.message.gas_limit, block.gas_limit)?;
compare_values("GasUsed", request_body.message.gas_used, block.gas_used)?;

full_validation(&block, self.provider(), &chain_spec).to_rpc_result()?;

let state = self.execute_and_verify_block(&block, chain_spec.clone())?;

self.check_proposer_payment(
&block,
&state,
&request_body.message.value,
&request_body.message.proposer_fee_recipient,
)
let request = ValidationRequest::new(request_body, self.provider());
request.validate().await
}
}

Expand Down
36 changes: 31 additions & 5 deletions src/rpc/utils.rs
View file
Original file line number Diff line number Diff line change
@@ -1,5 +1,6 @@
use crate::rpc::result::internal_rpc_err;
use jsonrpsee::core::RpcResult;
use reth_tracing::tracing;
use std::cmp::Ordering;

pub fn compare_values<T: std::cmp::PartialEq + std::fmt::Display>(
Expand Down Expand Up @@ -30,16 +31,41 @@ const MIN_GAS_LIMIT: u64 = 5000;
pub fn calc_gas_limit(parent_gas_limit: u64, desired_limit: u64) -> u64 {
// TODO: Understand why 1 is subtracted here
let delta = parent_gas_limit / GAS_LIMIT_BOUND_DIVISOR - 1;
let desired_limit = std::cmp::max(desired_limit, MIN_GAS_LIMIT);
match parent_gas_limit.cmp(&desired_limit) {
let desired_or_min_limit = std::cmp::max(desired_limit, MIN_GAS_LIMIT);
match parent_gas_limit.cmp(&desired_or_min_limit) {
Ordering::Less => {
let max_acceptable_limit = parent_gas_limit + delta;
std::cmp::min(max_acceptable_limit, desired_limit)
tracing::debug!(
parent_gas_limit,
delta,
desired_limit,
desired_or_min_limit,
max_acceptable_limit,
"Parent gas limit is less than desired/min limit"
);
std::cmp::min(max_acceptable_limit, desired_or_min_limit)
}
Ordering::Greater => {
let min_acceptable_limit = parent_gas_limit - delta;
std::cmp::max(min_acceptable_limit, desired_limit)
tracing::debug!(
parent_gas_limit,
delta,
desired_limit,
desired_or_min_limit,
min_acceptable_limit,
"Parent gas limit is greater than desired/min limit"
);
std::cmp::max(min_acceptable_limit, desired_or_min_limit)
}
Ordering::Equal => {
tracing::debug!(
parent_gas_limit,
delta,
desired_limit,
desired_or_min_limit,
"Parent gas limit is equal to desired/min limit"
);
parent_gas_limit
}
Ordering::Equal => parent_gas_limit,
}
}
Loading

0 comments on commit 6cd0468

Please sign in to comment.