Skip to content

Commit

Permalink
feat: improving executor and evm metrics (#286)
Browse files Browse the repository at this point in the history
  • Loading branch information
dinhani-cw authored Feb 27, 2024
1 parent d27f303 commit 9126337
Show file tree
Hide file tree
Showing 4 changed files with 109 additions and 74 deletions.
37 changes: 23 additions & 14 deletions src/eth/evm/revm.rs
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@
//! of the `Evm` trait, serving as a bridge between Ethereum's abstract operations and Stratus's storage mechanisms.
use std::sync::Arc;
use std::time::Instant;

use anyhow::anyhow;
use itertools::Itertools;
Expand Down Expand Up @@ -43,6 +44,7 @@ use crate::eth::primitives::SlotIndex;
use crate::eth::storage::StratusStorage;
use crate::ext::not;
use crate::ext::OptionExt;
use crate::infra::metrics;

/// Implementation of EVM using [`revm`](https://crates.io/crates/revm).
pub struct Revm {
Expand All @@ -69,6 +71,8 @@ impl Revm {

impl Evm for Revm {
fn execute(&mut self, input: EvmInput) -> anyhow::Result<Execution> {
let start = Instant::now();

// configure session
let evm = &mut self.evm;
let session = RevmDatabaseSession::new(Arc::clone(&self.storage), input.clone());
Expand Down Expand Up @@ -99,16 +103,20 @@ impl Evm for Revm {
#[cfg(not(debug_assertions))]
let evm_result = evm.transact();

match evm_result {
Ok(result) => {
let session = evm.take_db();
Ok(parse_revm_execution(result, session.input, session.storage_changes)?)
}
// parse result and track metrics
let session = evm.take_db();
let point_in_time = session.input.point_in_time.clone();

let result = match evm_result {
Ok(result) => Ok(parse_revm_execution(result, session.input, session.storage_changes)),
Err(e) => {
tracing::warn!(reason = ?e, "evm execution error");
Err(anyhow!("Error executing EVM transaction. Check logs for more information."))
}
}
};
metrics::inc_evm_execution(start.elapsed(), &point_in_time, result.is_ok());

result
}
}

Expand Down Expand Up @@ -224,19 +232,19 @@ impl Inspector<RevmDatabaseSession> for RevmInspector {
// Conversion
// -----------------------------------------------------------------------------

fn parse_revm_execution(revm_result: RevmResultAndState, input: EvmInput, execution_changes: ExecutionChanges) -> anyhow::Result<Execution> {
fn parse_revm_execution(revm_result: RevmResultAndState, input: EvmInput, execution_changes: ExecutionChanges) -> Execution {
let (result, output, logs, gas) = parse_revm_result(revm_result.result);
let execution_changes = parse_revm_state(revm_result.state, execution_changes)?;
let execution_changes = parse_revm_state(revm_result.state, execution_changes);

tracing::info!(?result, %gas, output_len = %output.len(), %output, "evm executed");
Ok(Execution {
Execution {
result,
output,
logs,
gas,
block_timestamp: input.block_timestamp,
changes: execution_changes.into_values().collect(),
})
}
}

fn parse_revm_result(result: RevmExecutionResult) -> (ExecutionResult, Bytes, Vec<Log>, Gas) {
Expand All @@ -263,7 +271,7 @@ fn parse_revm_result(result: RevmExecutionResult) -> (ExecutionResult, Bytes, Ve
}
}

fn parse_revm_state(revm_state: RevmState, mut execution_changes: ExecutionChanges) -> anyhow::Result<ExecutionChanges> {
fn parse_revm_state(revm_state: RevmState, mut execution_changes: ExecutionChanges) -> ExecutionChanges {
for (revm_address, revm_account) in revm_state {
let address: Address = revm_address.into();
if address.is_ignored() {
Expand Down Expand Up @@ -299,11 +307,12 @@ fn parse_revm_state(revm_state: RevmState, mut execution_changes: ExecutionChang
// status: touched (updated)
else if account_updated {
let Some(existing_account) = execution_changes.get_mut(&address) else {
tracing::error!(keys = ?execution_changes.keys(), reason = "account was updated, but it was not loaded by evm", %address);
return Err(anyhow!("Account '{}' was expected to be loaded by EVM, but it was not", address));
tracing::error!(keys = ?execution_changes.keys(), %address, "account updated, but not loaded by evm");
// TODO: panic! only when in dev-mode or try to refactor to avoid panic!
panic!("Account '{}' was expected to be loaded by EVM, but it was not", address);
};
existing_account.apply_changes(account, account_modified_slots);
}
}
Ok(execution_changes)
execution_changes
}
37 changes: 20 additions & 17 deletions src/eth/executor.rs
Original file line number Diff line number Diff line change
Expand Up @@ -76,13 +76,13 @@ impl EthExecutor {

/// Imports an external block using the offline flow.
pub async fn import_offline(&self, block: ExternalBlock, receipts: &HashMap<Hash, ExternalReceipt>) -> anyhow::Result<()> {
let start = Instant::now();
tracing::info!(number = %block.number(), "importing offline block");
let import_start = Instant::now();

// re-execute transactions
let mut executions: Vec<ExternalTransactionExecution> = Vec::with_capacity(block.transactions.len());
for tx in block.transactions.clone() {
let start = Instant::now();
let tx_start = Instant::now();
// find receipt
let Some(receipt) = receipts.get(&tx.hash()).cloned() else {
tracing::error!(hash = %tx.hash, "receipt is missing");
Expand All @@ -107,8 +107,8 @@ impl EthExecutor {

// temporarily save state to next transactions from the same block
self.storage.save_account_changes_to_temp(execution.clone()).await?;
metrics::inc_execution(start.elapsed(), true);
executions.push((tx, receipt, execution));
metrics::inc_executor_import_offline_transaction(tx_start.elapsed());
}
Err(e) => {
let json_tx = serde_json::to_string(&tx).unwrap();
Expand All @@ -119,21 +119,24 @@ impl EthExecutor {
}
}

// commit block
let block = Block::from_external(block, executions)?;
self.storage.set_block_number(*block.number()).await?;
if let Err(e) = self.storage.commit_to_perm(block.clone()).await {
let json_block = serde_json::to_string(&block).unwrap();
tracing::error!(reason = ?e, %json_block);
return Err(e.into());
};
metrics::inc_execution_and_commit(import_start.elapsed(), true);

metrics::inc_executor_import_offline(start.elapsed());
Ok(())
}

pub async fn import(&self, external_block: ExternalBlock, external_receipts: HashMap<H256, ExternalReceipt>) -> anyhow::Result<()> {
let start = Instant::now();

for external_transaction in <EthersBlock<ExternalTransaction>>::from(external_block.clone()).transactions {
let start = Instant::now();
let tx_start = Instant::now();
// Find the receipt for the current transaction.
let external_receipt = external_receipts
.get(&external_transaction.hash)
Expand All @@ -147,21 +150,15 @@ impl EthExecutor {

let evm_input = EvmInput::from_eth_transaction(transaction_input.clone());
let execution = self.execute_in_evm(evm_input).await?;
metrics::inc_execution(start.elapsed(), true);

execution.compare_with_receipt(external_receipt)?;
metrics::inc_executor_import_online_transaction(tx_start.elapsed());

let block = self.miner.lock().await.mine_with_one_transaction(transaction_input, execution).await?;

self.storage.commit_to_perm(block).await?;
metrics::inc_execution_and_commit(start.elapsed(), true);
metrics::inc_executor_import_online(tx_start.elapsed());
}

//TODO compare slots/changes
//TODO compare nonce
//TODO compare balance
//XXX panic in case of bad comparisson

metrics::inc_executor_import_online(start.elapsed());
Ok(())
}

Expand All @@ -175,6 +172,7 @@ impl EthExecutor {
///
/// TODO: too much cloning that can be optimized here.
pub async fn transact(&self, transaction: TransactionInput) -> anyhow::Result<Execution> {
let start = Instant::now();
tracing::info!(
hash = %transaction.hash,
nonce = %transaction.nonce,
Expand All @@ -193,7 +191,10 @@ impl EthExecutor {
}

// creates a block and performs the necessary notifications
self.mine_and_execute_transaction(transaction).await
let result = self.mine_and_execute_transaction(transaction).await;
metrics::inc_executor_transact(start.elapsed(), result.is_ok());

result
}

#[cfg(feature = "evm-mine")]
Expand Down Expand Up @@ -250,6 +251,7 @@ impl EthExecutor {

/// Execute a function and return the function output. State changes are ignored.
pub async fn call(&self, input: CallInput, point_in_time: StoragePointInTime) -> anyhow::Result<Execution> {
let start = Instant::now();
tracing::info!(
from = ?input.from,
to = ?input.to,
Expand All @@ -259,8 +261,9 @@ impl EthExecutor {
);

let evm_input = EvmInput::from_eth_call(input, point_in_time);
let execution = self.execute_in_evm(evm_input).await?;
Ok(execution)
let result = self.execute_in_evm(evm_input).await;
metrics::inc_executor_call(start.elapsed(), result.is_ok());
result
}

/// Submits a transaction to the EVM and awaits for its execution.
Expand Down
22 changes: 11 additions & 11 deletions src/eth/storage/stratus_storage.rs
Original file line number Diff line number Diff line change
Expand Up @@ -21,9 +21,9 @@ use crate::eth::storage::StorageError;
use crate::eth::storage::TemporaryStorage;
use crate::infra::metrics;

static TEMP_ORIGIN: &str = "temporary";
static PERM_ORIGIN: &str = "permanent";
static DEFAULT_ORIGIN: &str = "default";
const STORAGE_TEMP: &str = "temporary";
const STORAGE_PERM: &str = "permanent";
const DEFAULT_VALUE: &str = "default";

pub struct StratusStorage {
temp: Arc<dyn TemporaryStorage>,
Expand Down Expand Up @@ -74,18 +74,18 @@ impl StratusStorage {
match self.temp.maybe_read_account(address, point_in_time).await? {
Some(account) => {
tracing::debug!("account found in the temporary storage");
metrics::inc_storage_read_account(start.elapsed(), TEMP_ORIGIN, point_in_time, true);
metrics::inc_storage_read_account(start.elapsed(), STORAGE_TEMP, point_in_time, true);
Ok(account)
}
None => match self.perm.maybe_read_account(address, point_in_time).await? {
Some(account) => {
tracing::debug!("account found in the permanent storage");
metrics::inc_storage_read_account(start.elapsed(), PERM_ORIGIN, point_in_time, true);
metrics::inc_storage_read_account(start.elapsed(), STORAGE_PERM, point_in_time, true);
Ok(account)
}
None => {
tracing::debug!("account not found, assuming default value");
metrics::inc_storage_read_account(start.elapsed(), DEFAULT_ORIGIN, point_in_time, true);
metrics::inc_storage_read_account(start.elapsed(), DEFAULT_VALUE, point_in_time, true);
Ok(Account {
address: address.clone(),
..Account::default()
Expand All @@ -102,18 +102,18 @@ impl StratusStorage {
match self.temp.maybe_read_slot(address, slot_index, point_in_time).await? {
Some(slot) => {
tracing::debug!("slot found in the temporary storage");
metrics::inc_storage_read_slot(start.elapsed(), TEMP_ORIGIN, point_in_time, true);
metrics::inc_storage_read_slot(start.elapsed(), STORAGE_TEMP, point_in_time, true);
Ok(slot)
}
None => match self.perm.maybe_read_slot(address, slot_index, point_in_time).await? {
Some(slot) => {
tracing::debug!("slot found in the permanent storage");
metrics::inc_storage_read_slot(start.elapsed(), PERM_ORIGIN, point_in_time, true);
metrics::inc_storage_read_slot(start.elapsed(), STORAGE_PERM, point_in_time, true);
Ok(slot)
}
None => {
tracing::debug!("slot not found, assuming default value");
metrics::inc_storage_read_slot(start.elapsed(), DEFAULT_ORIGIN, point_in_time, true);
metrics::inc_storage_read_slot(start.elapsed(), DEFAULT_VALUE, point_in_time, true);
Ok(Slot {
index: slot_index.clone(),
..Default::default()
Expand Down Expand Up @@ -184,15 +184,15 @@ impl StratusStorage {
pub async fn reset_temp(&self) -> anyhow::Result<()> {
let start = Instant::now();
let result = self.temp.reset().await;
metrics::inc_storage_reset(start.elapsed(), result.is_ok());
metrics::inc_storage_reset(start.elapsed(), STORAGE_TEMP, result.is_ok());
result
}

/// Resets permanent storage down to specific block_number.
pub async fn reset_perm(&self, block_number: BlockNumber) -> anyhow::Result<()> {
let start = Instant::now();
let result = self.perm.reset_at(block_number).await;
metrics::inc_storage_reset(start.elapsed(), result.is_ok());
metrics::inc_storage_reset(start.elapsed(), STORAGE_PERM, result.is_ok());
result
}

Expand Down
Loading

0 comments on commit 9126337

Please sign in to comment.