Skip to content

Commit

Permalink
fix(sequencer): improve and fix instrumentation (#1255)
Browse files Browse the repository at this point in the history
## Summary
Generally improved instrumentation, including a fix for
`App::execute_transaction`.

## Background
There were a couple of async blocks spawned in tokio tasks which were
not instrumented, resulting in misleading tracing data for
`App::execute_transaction`. While investigating this, I discovered
several instances of tracing fields using `Debug` output, and also a few
functions which seemed to me like they would benefit from being
instrumented.

## Changes
- Applied the parent tracing span to the two spawned tasks.
- ~Replaced many `Debug` fields with `Display` ones. They were all down
to not being skipped via `skip_all`, so I replaced all instances of
`skip(...)` with `skip_all` meaning any fields to be included have to be
explicitly listed.~
- Removed all fields from instrumentation to cut down on tracing/log
noise.
- Added instrumentation to the transaction-checking functions and
mempool.

**Note:** ~I tried to largely preserve the fields which were previously
being instrumented, just changing them from `Debug` to `Display`. A very
few had no `Display` impl, so I excluded them. I think that almost all
of the fields could be omitted in a follow-up PR, since I don't think we
get much benefit from including things like addresses or balances in
instrumentation, and that only serves to clutter the output. Potentially
some of these fields are duplicated in the call chain, so even
restricting their inclusion to the relevant top-level function would
help.~

## Testing
Manually ran some tests with instrumentation enabled and eyeballed the
output.
  • Loading branch information
Fraser999 committed Jul 17, 2024
1 parent bd34b38 commit 45a6415
Show file tree
Hide file tree
Showing 24 changed files with 139 additions and 151 deletions.
8 changes: 1 addition & 7 deletions crates/astria-sequencer/src/accounts/action.rs
Original file line number Diff line number Diff line change
Expand Up @@ -105,13 +105,7 @@ impl ActionHandler for TransferAction {
.context("stateful transfer check failed")
}

#[instrument(
skip_all,
fields(
to = self.to.to_string(),
amount = self.amount,
)
)]
#[instrument(skip_all)]
async fn execute<S: StateWriteExt>(&self, state: &mut S, from: Address) -> Result<()> {
let fee = state
.get_transfer_base_fee()
Expand Down
6 changes: 3 additions & 3 deletions crates/astria-sequencer/src/accounts/component.rs
Original file line number Diff line number Diff line change
Expand Up @@ -23,7 +23,7 @@ pub(crate) struct AccountsComponent;
impl Component for AccountsComponent {
type AppState = astria_core::sequencer::GenesisState;

#[instrument(name = "AccountsComponent::init_chain", skip(state))]
#[instrument(name = "AccountsComponent::init_chain", skip_all)]
async fn init_chain<S: StateWriteExt>(mut state: S, app_state: &Self::AppState) -> Result<()> {
let native_asset = get_native_asset();
for account in app_state.accounts() {
Expand All @@ -38,15 +38,15 @@ impl Component for AccountsComponent {
Ok(())
}

#[instrument(name = "AccountsComponent::begin_block", skip(_state))]
#[instrument(name = "AccountsComponent::begin_block", skip_all)]
async fn begin_block<S: StateWriteExt + 'static>(
_state: &mut Arc<S>,
_begin_block: &BeginBlock,
) -> Result<()> {
Ok(())
}

#[instrument(name = "AccountsComponent::end_block", skip(_state))]
#[instrument(name = "AccountsComponent::end_block", skip_all)]
async fn end_block<S: StateWriteExt + 'static>(
_state: &mut Arc<S>,
_end_block: &EndBlock,
Expand Down
16 changes: 8 additions & 8 deletions crates/astria-sequencer/src/accounts/state_ext.rs
Original file line number Diff line number Diff line change
Expand Up @@ -65,7 +65,7 @@ fn nonce_storage_key(address: Address) -> String {

#[async_trait]
pub(crate) trait StateReadExt: StateRead {
#[instrument(skip_all, fields(address=%address))]
#[instrument(skip_all)]
async fn get_account_balances(&self, address: Address) -> Result<Vec<AssetBalance>> {
use crate::asset::state_ext::StateReadExt as _;

Expand Down Expand Up @@ -117,7 +117,7 @@ pub(crate) trait StateReadExt: StateRead {
Ok(balances)
}

#[instrument(skip_all, fields(address=%address, %asset))]
#[instrument(skip_all)]
async fn get_account_balance<'a, TAsset>(&self, address: Address, asset: TAsset) -> Result<u128>
where
TAsset: Into<asset::IbcPrefixed> + std::fmt::Display + Send,
Expand All @@ -133,7 +133,7 @@ pub(crate) trait StateReadExt: StateRead {
Ok(balance)
}

#[instrument(skip_all, fields(address=%address))]
#[instrument(skip_all)]
async fn get_account_nonce(&self, address: Address) -> Result<u32> {
let bytes = self
.get_raw(&nonce_storage_key(address))
Expand Down Expand Up @@ -167,7 +167,7 @@ impl<T: StateRead + ?Sized> StateReadExt for T {}

#[async_trait]
pub(crate) trait StateWriteExt: StateWrite {
#[instrument(skip(self, asset), fields(%asset))]
#[instrument(skip_all)]
fn put_account_balance<TAsset>(
&mut self,
address: Address,
Expand All @@ -182,14 +182,14 @@ pub(crate) trait StateWriteExt: StateWrite {
Ok(())
}

#[instrument(skip(self))]
#[instrument(skip_all)]
fn put_account_nonce(&mut self, address: Address, nonce: u32) -> Result<()> {
let bytes = borsh::to_vec(&Nonce(nonce)).context("failed to serialize nonce")?;
self.put_raw(nonce_storage_key(address), bytes);
Ok(())
}

#[instrument(skip(self, asset), fields(%asset))]
#[instrument(skip_all)]
async fn increase_balance<TAsset>(
&mut self,
address: Address,
Expand All @@ -215,7 +215,7 @@ pub(crate) trait StateWriteExt: StateWrite {
Ok(())
}

#[instrument(skip(self, asset), fields(%asset))]
#[instrument(skip_all)]
async fn decrease_balance<TAsset>(
&mut self,
address: Address,
Expand All @@ -241,7 +241,7 @@ pub(crate) trait StateWriteExt: StateWrite {
Ok(())
}

#[instrument(skip(self))]
#[instrument(skip_all)]
fn put_transfer_base_fee(&mut self, fee: u128) -> Result<()> {
let bytes = borsh::to_vec(&Fee(fee)).context("failed to serialize fee")?;
self.put_raw(TRANSFER_BASE_FEE_STORAGE_KEY.to_string(), bytes);
Expand Down
4 changes: 2 additions & 2 deletions crates/astria-sequencer/src/address/state_ext.rs
Original file line number Diff line number Diff line change
Expand Up @@ -16,7 +16,7 @@ fn base_prefix_key() -> &'static str {

#[async_trait]
pub(crate) trait StateReadExt: StateRead {
#[instrument(skip(self))]
#[instrument(skip_all)]
async fn get_base_prefix(&self) -> Result<String> {
let Some(bytes) = self
.get_raw(base_prefix_key())
Expand All @@ -33,7 +33,7 @@ impl<T: ?Sized + StateRead> StateReadExt for T {}

#[async_trait]
pub(crate) trait StateWriteExt: StateWrite {
#[instrument(skip(self))]
#[instrument(skip_all)]
fn put_base_prefix(&mut self, prefix: &str) {
self.put_raw(base_prefix_key().into(), prefix.into());
}
Expand Down
17 changes: 9 additions & 8 deletions crates/astria-sequencer/src/app/mod.rs
Original file line number Diff line number Diff line change
Expand Up @@ -59,6 +59,7 @@ use tracing::{
debug,
info,
instrument,
Instrument as _,
};

use crate::{
Expand Down Expand Up @@ -984,21 +985,21 @@ impl App {
}

/// Executes a signed transaction.
#[instrument(name = "App::execute_transaction", skip_all, fields(
signed_transaction_hash = %telemetry::display::base64(&signed_tx.sha256_of_proto_encoding()),
sender_address_bytes = %telemetry::display::base64(&signed_tx.address_bytes()),
))]
#[instrument(name = "App::execute_transaction", skip_all)]
pub(crate) async fn execute_transaction(
&mut self,
signed_tx: Arc<SignedTransaction>,
) -> anyhow::Result<Vec<Event>> {
let signed_tx_2 = signed_tx.clone();
let stateless =
tokio::spawn(async move { transaction::check_stateless(&signed_tx_2).await });
let stateless = tokio::spawn(
async move { transaction::check_stateless(&signed_tx_2).await }.in_current_span(),
);
let signed_tx_2 = signed_tx.clone();
let state2 = self.state.clone();
let stateful =
tokio::spawn(async move { transaction::check_stateful(&signed_tx_2, &state2).await });
let stateful = tokio::spawn(
async move { transaction::check_stateful(&signed_tx_2, &state2).await }
.in_current_span(),
);

stateless
.await
Expand Down
6 changes: 3 additions & 3 deletions crates/astria-sequencer/src/asset/state_ext.rs
Original file line number Diff line number Diff line change
Expand Up @@ -27,7 +27,7 @@ fn asset_storage_key<TAsset: Into<asset::IbcPrefixed>>(asset: TAsset) -> String

#[async_trait]
pub(crate) trait StateReadExt: StateRead {
#[instrument(skip(self, asset), fields(%asset))]
#[instrument(skip_all)]
async fn has_ibc_asset<TAsset>(&self, asset: TAsset) -> Result<bool>
where
TAsset: Into<asset::IbcPrefixed> + std::fmt::Display + Send,
Expand All @@ -39,7 +39,7 @@ pub(crate) trait StateReadExt: StateRead {
.is_some())
}

#[instrument(skip(self))]
#[instrument(skip_all)]
async fn map_ibc_to_trace_prefixed_asset(
&self,
asset: asset::IbcPrefixed,
Expand All @@ -65,7 +65,7 @@ impl<T: ?Sized + StateRead> StateReadExt for T {}

#[async_trait]
pub(crate) trait StateWriteExt: StateWrite {
#[instrument(skip(self))]
#[instrument(skip_all)]
fn put_ibc_asset(&mut self, asset: &denom::TracePrefixed) -> Result<()> {
let bytes = borsh::to_vec(&DenominationTrace(asset.to_string()))
.context("failed to serialize asset")?;
Expand Down
6 changes: 3 additions & 3 deletions crates/astria-sequencer/src/authority/component.rs
Original file line number Diff line number Diff line change
Expand Up @@ -34,7 +34,7 @@ pub(crate) struct AuthorityComponentAppState {
impl Component for AuthorityComponent {
type AppState = AuthorityComponentAppState;

#[instrument(name = "AuthorityComponent::init_chain", skip(state))]
#[instrument(name = "AuthorityComponent::init_chain", skip_all)]
async fn init_chain<S: StateWriteExt>(mut state: S, app_state: &Self::AppState) -> Result<()> {
// set sudo key and initial validator set
state
Expand All @@ -47,7 +47,7 @@ impl Component for AuthorityComponent {
Ok(())
}

#[instrument(name = "AuthorityComponent::begin_block", skip(state))]
#[instrument(name = "AuthorityComponent::begin_block", skip_all)]
async fn begin_block<S: StateWriteExt + 'static>(
state: &mut Arc<S>,
begin_block: &BeginBlock,
Expand All @@ -69,7 +69,7 @@ impl Component for AuthorityComponent {
Ok(())
}

#[instrument(name = "AuthorityComponent::end_block", skip(state))]
#[instrument(name = "AuthorityComponent::end_block", skip_all)]
async fn end_block<S: StateWriteExt + StateReadExt + 'static>(
state: &mut Arc<S>,
_end_block: &EndBlock,
Expand Down
14 changes: 7 additions & 7 deletions crates/astria-sequencer/src/authority/state_ext.rs
Original file line number Diff line number Diff line change
Expand Up @@ -107,7 +107,7 @@ const VALIDATOR_UPDATES_KEY: &[u8] = b"valupdates";

#[async_trait]
pub(crate) trait StateReadExt: StateRead {
#[instrument(skip(self))]
#[instrument(skip_all)]
async fn get_sudo_address(&self) -> Result<Address> {
let Some(bytes) = self
.get_raw(SUDO_STORAGE_KEY)
Expand All @@ -122,7 +122,7 @@ pub(crate) trait StateReadExt: StateRead {
Ok(crate::address::base_prefixed(address_bytes))
}

#[instrument(skip(self))]
#[instrument(skip_all)]
async fn get_validator_set(&self) -> Result<ValidatorSet> {
let Some(bytes) = self
.get_raw(VALIDATOR_SET_STORAGE_KEY)
Expand All @@ -138,7 +138,7 @@ pub(crate) trait StateReadExt: StateRead {
Ok(ValidatorSet(validator_set))
}

#[instrument(skip(self))]
#[instrument(skip_all)]
async fn get_validator_updates(&self) -> Result<ValidatorSet> {
let Some(bytes) = self
.nonverifiable_get_raw(VALIDATOR_UPDATES_KEY)
Expand All @@ -159,7 +159,7 @@ impl<T: StateRead> StateReadExt for T {}

#[async_trait]
pub(crate) trait StateWriteExt: StateWrite {
#[instrument(skip(self))]
#[instrument(skip_all)]
fn put_sudo_address(&mut self, address: Address) -> Result<()> {
self.put_raw(
SUDO_STORAGE_KEY.to_string(),
Expand All @@ -169,7 +169,7 @@ pub(crate) trait StateWriteExt: StateWrite {
Ok(())
}

#[instrument(skip(self))]
#[instrument(skip_all)]
fn put_validator_set(&mut self, validator_set: ValidatorSet) -> Result<()> {
self.put_raw(
VALIDATOR_SET_STORAGE_KEY.to_string(),
Expand All @@ -178,7 +178,7 @@ pub(crate) trait StateWriteExt: StateWrite {
Ok(())
}

#[instrument(skip(self))]
#[instrument(skip_all)]
fn put_validator_updates(&mut self, validator_updates: ValidatorSet) -> Result<()> {
self.nonverifiable_put_raw(
VALIDATOR_UPDATES_KEY.to_vec(),
Expand All @@ -188,7 +188,7 @@ pub(crate) trait StateWriteExt: StateWrite {
Ok(())
}

#[instrument(skip(self))]
#[instrument(skip_all)]
fn clear_validator_updates(&mut self) {
self.nonverifiable_delete(VALIDATOR_UPDATES_KEY.to_vec());
}
Expand Down
6 changes: 3 additions & 3 deletions crates/astria-sequencer/src/bridge/component.rs
Original file line number Diff line number Diff line change
Expand Up @@ -17,7 +17,7 @@ pub(crate) struct BridgeComponent;
impl Component for BridgeComponent {
type AppState = astria_core::sequencer::GenesisState;

#[instrument(name = "BridgeComponent::init_chain", skip(state))]
#[instrument(name = "BridgeComponent::init_chain", skip_all)]
async fn init_chain<S: StateWriteExt>(mut state: S, app_state: &Self::AppState) -> Result<()> {
state.put_init_bridge_account_base_fee(app_state.fees().init_bridge_account_base_fee);
state.put_bridge_lock_byte_cost_multiplier(
Expand All @@ -27,15 +27,15 @@ impl Component for BridgeComponent {
Ok(())
}

#[instrument(name = "BridgeComponent::begin_block", skip(_state))]
#[instrument(name = "BridgeComponent::begin_block", skip_all)]
async fn begin_block<S: StateWriteExt + 'static>(
_state: &mut Arc<S>,
_begin_block: &BeginBlock,
) -> Result<()> {
Ok(())
}

#[instrument(name = "BridgeComponent::end_block", skip(_state))]
#[instrument(name = "BridgeComponent::end_block", skip_all)]
async fn end_block<S: StateWriteExt + 'static>(
_state: &mut Arc<S>,
_end_block: &EndBlock,
Expand Down
Loading

0 comments on commit 45a6415

Please sign in to comment.