Skip to content
This repository has been archived by the owner on Nov 15, 2023. It is now read-only.

Improve error handling in approval voting block import #5283

Merged
merged 4 commits into from
Apr 8, 2022
Merged

Improve error handling in approval voting block import #5283

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
b748c8a
Print out original the runtime API error
koute Apr 8, 2022
9d625e1
Improved error handling in approval voting block import
koute Apr 8, 2022
8d5e019
Fix test
koute Apr 8, 2022
d3d392c
Update comment
koute Apr 8, 2022
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
View file
Open in desktop

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

1 change: 1 addition & 0 deletions node/core/approval-voting/Cargo.toml
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,7 @@ merlin = "2.0"
schnorrkel = "0.9.1"
kvdb = "0.11.0"
derive_more = "0.99.17"
thiserror = "1.0.30"

polkadot-node-subsystem = { path = "../../subsystem" }
polkadot-node-subsystem-util = { path = "../../subsystem-util" }
Expand Down
81 changes: 53 additions & 28 deletions node/core/approval-voting/src/import.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -38,7 +38,7 @@ use polkadot_node_subsystem::{
ApprovalDistributionMessage, ChainApiMessage, ChainSelectionMessage, RuntimeApiMessage,
RuntimeApiRequest,
},
overseer, SubsystemContext, SubsystemError, SubsystemResult,
overseer, RuntimeApiError, SubsystemContext, SubsystemError, SubsystemResult,
};
use polkadot_node_subsystem_util::{
determine_new_blocks,
Expand Down Expand Up @@ -66,6 +66,7 @@ use crate::{

use super::{State, LOG_TARGET};

#[derive(Debug)]
struct ImportedBlockInfo {
included_candidates: Vec<(CandidateHash, CandidateReceipt, CoreIndex, GroupIndex)>,
session_index: SessionIndex,
Expand All @@ -82,14 +83,36 @@ struct ImportedBlockInfoEnv<'a> {
keystore: &'a LocalKeystore,
}

// Computes information about the imported block. Returns `None` if the info couldn't be extracted -
// failure to communicate with overseer,
#[derive(Debug, thiserror::Error)]
enum ImportedBlockInfoError {
// NOTE: The `RuntimeApiError` already prints out which request it was,
// so it's not necessary to include that here.
#[error(transparent)]
RuntimeError(RuntimeApiError),

#[error("future cancalled while requesting {0}")]
FutureCancelled(&'static str, futures::channel::oneshot::Canceled),
Copy link
Contributor

Choose a reason for hiding this comment

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

Canceled should be annotated with #[source]

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Ah, I missed that.

That said, in this case in practice since Canceled is a ZST and doesn't actually carry any information it shouldn't make any practical difference.

I'm happy to make a followup PR and add this in though.

Copy link
Contributor

Choose a reason for hiding this comment

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

Just a nit :)


#[error(transparent)]
ApprovalError(approval_types::ApprovalError),

#[error("block is from an ancient session")]
BlockFromAncientSession,

#[error("session info unavailable")]
SessionInfoUnavailable,

#[error("VRF info unavailable")]
VrfInfoUnavailable,
}

/// Computes information about the imported block. Returns an error if the info couldn't be extracted.
async fn imported_block_info(
ctx: &mut (impl SubsystemContext + overseer::SubsystemContext),
env: ImportedBlockInfoEnv<'_>,
block_hash: Hash,
block_header: &Header,
) -> SubsystemResult<Option<ImportedBlockInfo>> {
) -> Result<ImportedBlockInfo, ImportedBlockInfoError> {
// Ignore any runtime API errors - that means these blocks are old and finalized.
// Only unfinalized blocks factor into the approval voting process.

Expand All @@ -104,8 +127,9 @@ async fn imported_block_info(

let events: Vec<CandidateEvent> = match c_rx.await {
Ok(Ok(events)) => events,
Ok(Err(_)) => return Ok(None),
Err(_) => return Ok(None),
Ok(Err(error)) => return Err(ImportedBlockInfoError::RuntimeError(error)),
Err(error) =>
return Err(ImportedBlockInfoError::FutureCancelled("CandidateEvents", error)),
};

events
Expand All @@ -130,8 +154,9 @@ async fn imported_block_info(

let session_index = match s_rx.await {
Ok(Ok(s)) => s,
Ok(Err(_)) => return Ok(None),
Err(_) => return Ok(None),
Ok(Err(error)) => return Err(ImportedBlockInfoError::RuntimeError(error)),
Err(error) =>
return Err(ImportedBlockInfoError::FutureCancelled("SessionIndexForChild", error)),
};

if env
Expand All @@ -146,7 +171,7 @@ async fn imported_block_info(
session_index
);

return Ok(None)
return Err(ImportedBlockInfoError::BlockFromAncientSession)
}

session_index
Expand Down Expand Up @@ -180,8 +205,9 @@ async fn imported_block_info(

match s_rx.await {
Ok(Ok(s)) => s,
Ok(Err(_)) => return Ok(None),
Err(_) => return Ok(None),
Ok(Err(error)) => return Err(ImportedBlockInfoError::RuntimeError(error)),
Err(error) =>
return Err(ImportedBlockInfoError::FutureCancelled("CurrentBabeEpoch", error)),
}
};

Expand All @@ -191,7 +217,7 @@ async fn imported_block_info(
None => {
gum::debug!(target: LOG_TARGET, "Session info unavailable for block {}", block_hash,);

return Ok(None)
return Err(ImportedBlockInfoError::SessionInfoUnavailable)
},
};

Expand Down Expand Up @@ -220,7 +246,7 @@ async fn imported_block_info(

(assignments, slot, relay_vrf)
},
Err(_) => return Ok(None),
Err(error) => return Err(ImportedBlockInfoError::ApprovalError(error)),
}
},
None => {
Expand All @@ -230,7 +256,7 @@ async fn imported_block_info(
block_hash,
);

return Ok(None)
return Err(ImportedBlockInfoError::VrfInfoUnavailable)
},
}
};
Expand Down Expand Up @@ -264,15 +290,15 @@ async fn imported_block_info(
},
});

Ok(Some(ImportedBlockInfo {
Ok(ImportedBlockInfo {
included_candidates,
session_index,
assignments,
n_validators: session_info.validators.len(),
relay_vrf_story,
slot,
force_approve,
}))
})
}

/// Information about a block and imported candidates.
Expand Down Expand Up @@ -382,9 +408,9 @@ pub(crate) async fn handle_new_head(
keystore: &state.keystore,
};

match imported_block_info(ctx, env, block_hash, &block_header).await? {
Some(i) => imported_blocks_and_info.push((block_hash, block_header, i)),
None => {
match imported_block_info(ctx, env, block_hash, &block_header).await {
Ok(i) => imported_blocks_and_info.push((block_hash, block_header, i)),
Err(error) => {
// It's possible that we've lost a race with finality.
let (tx, rx) = oneshot::channel();
ctx.send_message(ChainApiMessage::FinalizedBlockHash(
Expand All @@ -403,8 +429,9 @@ pub(crate) async fn handle_new_head(
// in the approval-db.
gum::warn!(
target: LOG_TARGET,
"Unable to gather info about imported block {:?}. Skipping chain.",
"Skipping chain: unable to gather info about imported block {:?}: {}",
(block_hash, block_header.number),
error,
);
}

Expand Down Expand Up @@ -757,8 +784,7 @@ pub(crate) mod tests {
keystore: &LocalKeystore::in_memory(),
};

let info =
imported_block_info(&mut ctx, env, hash, &header).await.unwrap().unwrap();
let info = imported_block_info(&mut ctx, env, hash, &header).await.unwrap();

assert_eq!(info.included_candidates, included_candidates);
assert_eq!(info.session_index, session);
Expand Down Expand Up @@ -866,9 +892,9 @@ pub(crate) mod tests {
keystore: &LocalKeystore::in_memory(),
};

let info = imported_block_info(&mut ctx, env, hash, &header).await.unwrap();
let info = imported_block_info(&mut ctx, env, hash, &header).await;

assert!(info.is_none());
assert_matches!(info, Err(ImportedBlockInfoError::VrfInfoUnavailable));
})
};

Expand Down Expand Up @@ -964,9 +990,9 @@ pub(crate) mod tests {
keystore: &LocalKeystore::in_memory(),
};

let info = imported_block_info(&mut ctx, env, hash, &header).await.unwrap();
let info = imported_block_info(&mut ctx, env, hash, &header).await;

assert!(info.is_none());
assert_matches!(info, Err(ImportedBlockInfoError::BlockFromAncientSession));
eskimor marked this conversation as resolved.
Show resolved Hide resolved
})
};

Expand Down Expand Up @@ -1063,8 +1089,7 @@ pub(crate) mod tests {
keystore: &LocalKeystore::in_memory(),
};

let info =
imported_block_info(&mut ctx, env, hash, &header).await.unwrap().unwrap();
let info = imported_block_info(&mut ctx, env, hash, &header).await.unwrap();

assert_eq!(info.included_candidates, included_candidates);
assert_eq!(info.session_index, session);
Expand Down
4 changes: 2 additions & 2 deletions node/subsystem-types/src/errors.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -21,8 +21,8 @@ use crate::JaegerError;
/// A description of an error causing the runtime API request to be unservable.
#[derive(thiserror::Error, Debug, Clone)]
pub enum RuntimeApiError {
/// The runtime API cannot be executed due to a
#[error("The runtime API '{runtime_api_name}' cannot be executed")]
/// The runtime API cannot be executed due to a runtime error.
#[error("The runtime API '{runtime_api_name}' cannot be executed: {source}")]
Copy link
Contributor

Choose a reason for hiding this comment

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

nit: source will be printed twice now in the backtrace, once as part of the backtrace and as part of the error message itself iirc

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Do you know how you'd have to print it out to actually get it printed out twice?

Because when printed out through a normal Display trait:

    #[test]
    fn test_foobar() {
        #[derive(thiserror::Error, Debug)]
        #[error("source")]
        struct Source;
        let err = RuntimeApiError::Execution { runtime_api_name: "Test", source: Arc::new(Source) };
        panic!("{}", err);
    }

it's printed out like this:

thread 'import::tests::test_foobar' panicked at 'The runtime API 'Test' cannot be executed: source', node/core/approval-voting/src/import.rs:1351:9

And we usually print out errors through Display (or Debug).

Execution {
/// The runtime API being called
runtime_api_name: &'static str,
Expand Down