State metrics possible changes (#5168)

* Registering state from overlay.

* fix

* fix2

* Apply suggestions from code review

Co-authored-by: Bastian Köcher <bkchr@users.noreply.github.com>
This commit is contained in:
cheme
2020-04-01 19:46:40 +02:00
committed by GitHub
parent a8aedfa16f
commit 58578af074
17 changed files with 232 additions and 33 deletions
+7 -3
View File
@@ -179,8 +179,12 @@ pub struct IoInfo {
pub state_reads: u64,
/// State reads (keys) from cache.
pub state_reads_cache: u64,
/// State reads (keys) from cache.
/// State reads (keys)
pub state_writes: u64,
/// State write (keys) already cached.
pub state_writes_cache: u64,
/// State write (trie nodes) to backend db.
pub state_writes_nodes: u64,
}
/// Usage statistics for running client instance.
@@ -202,7 +206,7 @@ impl fmt::Display for UsageInfo {
f,
"caches: ({} state, {} db overlay), \
state db: ({} non-canonical, {} pruning, {} pinned), \
i/o: ({} tx, {} write, {} read, {} avg tx, {}/{} key cache reads/total, {} key writes)",
i/o: ({} tx, {} write, {} read, {} avg tx, {}/{} key cache reads/total, {} trie nodes writes)",
self.memory.state_cache,
self.memory.database_cache,
self.memory.state_db.non_canonical,
@@ -214,7 +218,7 @@ impl fmt::Display for UsageInfo {
self.io.average_transaction_size,
self.io.state_reads_cache,
self.io.state_reads,
self.io.state_writes,
self.io.state_writes_nodes,
)
}
}
+8
View File
@@ -305,6 +305,14 @@ impl<B: BlockT> StateBackend<HashFor<B>> for BenchmarkingState<B> {
self.reopen()?;
Ok(())
}
fn register_overlay_stats(&mut self, stats: &sp_state_machine::StateMachineStats) {
self.state.borrow_mut().as_mut().map(|s| s.register_overlay_stats(stats));
}
fn usage_info(&self) -> sp_state_machine::UsageInfo {
self.state.borrow().as_ref().map_or(sp_state_machine::UsageInfo::empty(), |s| s.usage_info())
}
}
impl<Block: BlockT> std::fmt::Debug for BenchmarkingState<Block> {
+29 -5
View File
@@ -73,7 +73,7 @@ use sc_executor::RuntimeInfo;
use sp_state_machine::{
DBValue, ChangesTrieTransaction, ChangesTrieCacheAction, UsageInfo as StateUsageInfo,
StorageCollection, ChildStorageCollection,
backend::Backend as StateBackend,
backend::Backend as StateBackend, StateMachineStats,
};
use crate::utils::{DatabaseType, Meta, db_err, meta_keys, read_db, read_meta};
use crate::changes_tries_storage::{DbChangesTrieStorage, DbChangesTrieStorageTransaction};
@@ -256,6 +256,14 @@ impl<B: BlockT> StateBackend<HashFor<B>> for RefTrackingState<B> {
{
self.state.as_trie_backend()
}
fn register_overlay_stats(&mut self, stats: &StateMachineStats) {
self.state.register_overlay_stats(stats);
}
fn usage_info(&self) -> StateUsageInfo {
self.state.usage_info()
}
}
/// Database settings.
@@ -1116,6 +1124,8 @@ impl<Block: BlockT> Backend<Block> {
let mut changeset: sc_state_db::ChangeSet<Vec<u8>> = sc_state_db::ChangeSet::default();
let mut ops: u64 = 0;
let mut bytes: u64 = 0;
let mut removal: u64 = 0;
let mut bytes_removal: u64 = 0;
for (key, (val, rc)) in operation.db_updates.drain() {
if rc > 0 {
ops += 1;
@@ -1123,14 +1133,26 @@ impl<Block: BlockT> Backend<Block> {
changeset.inserted.push((key, val.to_vec()));
} else if rc < 0 {
ops += 1;
bytes += key.len() as u64;
removal += 1;
bytes_removal += key.len() as u64;
changeset.deleted.push(key);
}
}
self.state_usage.tally_writes(ops, bytes);
self.state_usage.tally_writes_nodes(ops, bytes);
self.state_usage.tally_removed_nodes(removal, bytes_removal);
let mut ops: u64 = 0;
let mut bytes: u64 = 0;
for (key, value) in operation.storage_updates.iter()
.chain(operation.child_storage_updates.iter().flat_map(|(_, s)| s.iter())) {
ops += 1;
bytes += key.len() as u64;
if let Some(v) = value.as_ref() {
bytes += v.len() as u64;
}
}
self.state_usage.tally_writes(ops, bytes);
let number_u64 = number.saturated_into::<u64>();
let commit = self.storage.state_db.insert_block(
&hash,
@@ -1498,8 +1520,10 @@ impl<Block: BlockT> sc_client_api::backend::Backend<Block> for Backend<Block> {
reads: io_stats.reads,
average_transaction_size: io_stats.avg_transaction_size() as u64,
state_reads: state_stats.reads.ops,
state_reads_cache: state_stats.cache_reads.ops,
state_writes: state_stats.writes.ops,
state_writes_cache: state_stats.overlay_writes.ops,
state_reads_cache: state_stats.cache_reads.ops,
state_writes_nodes: state_stats.nodes_writes.ops,
},
})
}
+3 -1
View File
@@ -592,8 +592,10 @@ impl<Block> LightBlockchainStorage<Block> for LightStorage<Block>
average_transaction_size: io_stats.avg_transaction_size() as u64,
// Light client does not track those
state_reads: 0,
state_reads_cache: 0,
state_writes: 0,
state_reads_cache: 0,
state_writes_cache: 0,
state_writes_nodes: 0,
}
})
}
+29 -3
View File
@@ -25,6 +25,10 @@ pub struct StateUsageStats {
bytes_read: AtomicU64,
writes: AtomicU64,
bytes_written: AtomicU64,
writes_nodes: AtomicU64,
bytes_written_nodes: AtomicU64,
removed_nodes: AtomicU64,
bytes_removed_nodes: AtomicU64,
reads_cache: AtomicU64,
bytes_read_cache: AtomicU64,
}
@@ -38,6 +42,10 @@ impl StateUsageStats {
bytes_read: 0.into(),
writes: 0.into(),
bytes_written: 0.into(),
writes_nodes: 0.into(),
bytes_written_nodes: 0.into(),
removed_nodes: 0.into(),
bytes_removed_nodes: 0.into(),
reads_cache: 0.into(),
bytes_read_cache: 0.into(),
}
@@ -70,7 +78,19 @@ impl StateUsageStats {
val
}
/// Tally some write operations, including their byte count.
/// Tally some write trie nodes operations, including their byte count.
pub fn tally_writes_nodes(&self, ops: u64, data_bytes: u64) {
self.writes_nodes.fetch_add(ops, AtomicOrdering::Relaxed);
self.bytes_written_nodes.fetch_add(data_bytes, AtomicOrdering::Relaxed);
}
/// Tally some removed trie nodes operations, including their byte count.
pub fn tally_removed_nodes(&self, ops: u64, data_bytes: u64) {
self.removed_nodes.fetch_add(ops, AtomicOrdering::Relaxed);
self.bytes_removed_nodes.fetch_add(data_bytes, AtomicOrdering::Relaxed);
}
/// Tally some write trie nodes operations, including their byte count.
pub fn tally_writes(&self, ops: u64, data_bytes: u64) {
self.writes.fetch_add(ops, AtomicOrdering::Relaxed);
self.bytes_written.fetch_add(data_bytes, AtomicOrdering::Relaxed);
@@ -80,8 +100,10 @@ impl StateUsageStats {
pub fn merge_sm(&self, info: sp_state_machine::UsageInfo) {
self.reads.fetch_add(info.reads.ops, AtomicOrdering::Relaxed);
self.bytes_read.fetch_add(info.reads.bytes, AtomicOrdering::Relaxed);
self.writes.fetch_add(info.writes.ops, AtomicOrdering::Relaxed);
self.bytes_written.fetch_add(info.writes.bytes, AtomicOrdering::Relaxed);
self.writes_nodes.fetch_add(info.nodes_writes.ops, AtomicOrdering::Relaxed);
self.bytes_written_nodes.fetch_add(info.nodes_writes.bytes, AtomicOrdering::Relaxed);
self.removed_nodes.fetch_add(info.removed_nodes.ops, AtomicOrdering::Relaxed);
self.bytes_removed_nodes.fetch_add(info.removed_nodes.bytes, AtomicOrdering::Relaxed);
self.reads_cache.fetch_add(info.cache_reads.ops, AtomicOrdering::Relaxed);
self.bytes_read_cache.fetch_add(info.cache_reads.bytes, AtomicOrdering::Relaxed);
}
@@ -100,7 +122,11 @@ impl StateUsageStats {
sp_state_machine::UsageInfo {
reads: unit(&self.reads, &self.bytes_read),
writes: unit(&self.writes, &self.bytes_written),
nodes_writes: unit(&self.writes_nodes, &self.bytes_written_nodes),
removed_nodes: unit(&self.removed_nodes, &self.bytes_removed_nodes),
cache_reads: unit(&self.reads_cache, &self.bytes_read_cache),
modified_reads: Default::default(),
overlay_writes: Default::default(),
// TODO: Proper tracking state of memory footprint here requires
// imposing `MallocSizeOf` requirement on half of the codebase,
// so it is an open question how to do it better
+14 -1
View File
@@ -299,6 +299,8 @@ pub struct CacheChanges<B: BlockT> {
pub struct CachingState<S, B: BlockT> {
/// Usage statistics
usage: StateUsageStats,
/// State machine registered stats
overlay_stats: sp_state_machine::StateMachineStats,
/// Backing state.
state: S,
/// Cache data.
@@ -428,6 +430,7 @@ impl<S: StateBackend<HashFor<B>>, B: BlockT> CachingState<S, B> {
) -> Self {
CachingState {
usage: StateUsageStats::new(),
overlay_stats: sp_state_machine::StateMachineStats::default(),
state,
cache: CacheChanges {
shared_cache,
@@ -663,8 +666,14 @@ impl<S: StateBackend<HashFor<B>>, B: BlockT> StateBackend<HashFor<B>> for Cachin
self.state.as_trie_backend()
}
fn register_overlay_stats(&mut self, stats: &sp_state_machine::StateMachineStats) {
self.overlay_stats.add(stats);
}
fn usage_info(&self) -> sp_state_machine::UsageInfo {
self.usage.take()
let mut info = self.usage.take();
info.include_state_machine_states(&self.overlay_stats);
info
}
}
@@ -852,6 +861,10 @@ impl<S: StateBackend<HashFor<B>>, B: BlockT> StateBackend<HashFor<B>> for Syncin
.as_trie_backend()
}
fn register_overlay_stats(&mut self, stats: &sp_state_machine::StateMachineStats) {
self.caching_state().register_overlay_stats(stats);
}
fn usage_info(&self) -> sp_state_machine::UsageInfo {
self.caching_state().usage_info()
}
+12 -10
View File
@@ -160,36 +160,38 @@ where
recorder.clone(),
);
StateMachine::new(
let changes = &mut *changes.borrow_mut();
let mut state_machine = StateMachine::new(
&backend,
changes_trie_state,
&mut *changes.borrow_mut(),
changes,
&self.executor,
method,
call_data,
extensions.unwrap_or_default(),
&runtime_code,
self.spawn_handle.clone(),
)
);
// TODO: https://github.com/paritytech/substrate/issues/4455
// .with_storage_transaction_cache(storage_transaction_cache.as_mut().map(|c| &mut **c))
.execute_using_consensus_failure_handler(execution_manager, native_call)
state_machine.execute_using_consensus_failure_handler(execution_manager, native_call)
},
None => {
let state_runtime_code = sp_state_machine::backend::BackendRuntimeCode::new(&state);
StateMachine::new(
let runtime_code = state_runtime_code.runtime_code()?;
let changes = &mut *changes.borrow_mut();
let mut state_machine = StateMachine::new(
&state,
changes_trie_state,
&mut *changes.borrow_mut(),
changes,
&self.executor,
method,
call_data,
extensions.unwrap_or_default(),
&state_runtime_code.runtime_code()?,
&runtime_code,
self.spawn_handle.clone(),
)
.with_storage_transaction_cache(storage_transaction_cache.as_mut().map(|c| &mut **c))
.execute_using_consensus_failure_handler(execution_manager, native_call)
).with_storage_transaction_cache(storage_transaction_cache.as_mut().map(|c| &mut **c));
state_machine.execute_using_consensus_failure_handler(execution_manager, native_call)
}
}.map_err(Into::into)
}
+6
View File
@@ -505,6 +505,12 @@ impl<H: Hasher> StateBackend<H> for GenesisOrUnavailableState<H>
}
}
fn register_overlay_stats(&mut self, _stats: &sp_state_machine::StateMachineStats) { }
fn usage_info(&self) -> sp_state_machine::UsageInfo {
sp_state_machine::UsageInfo::empty()
}
fn as_trie_backend(&mut self) -> Option<&TrieBackend<Self::TrieBackendStorage, H>> {
match self {
GenesisOrUnavailableState::Genesis(ref mut state) => state.as_trie_backend(),
@@ -206,13 +206,16 @@ pub trait Backend<H: Hasher>: std::fmt::Debug {
(root, txs)
}
/// Register stats from overlay of state machine.
///
/// By default nothing is registered.
fn register_overlay_stats(&mut self, _stats: &crate::stats::StateMachineStats);
/// Query backend usage statistics (i/o, memory)
///
/// Not all implementations are expected to be able to do this. In the
/// case when they don't, empty statistics is returned.
fn usage_info(&self) -> UsageInfo {
UsageInfo::empty()
}
fn usage_info(&self) -> UsageInfo;
/// Wipe the state database.
fn wipe(&self) -> Result<(), Self::Error> {
@@ -308,10 +311,12 @@ impl<'a, T: Backend<H>, H: Hasher> Backend<H> for &'a T {
(*self).for_key_values_with_prefix(prefix, f);
}
fn register_overlay_stats(&mut self, _stats: &crate::stats::StateMachineStats) { }
fn usage_info(&self) -> UsageInfo {
(*self).usage_info()
}
}
}
/// Trait that allows consolidate two transactions together.
pub trait Consolidate {
@@ -469,6 +469,7 @@ mod test {
].into_iter().collect(),
},
collect_extrinsics: true,
stats: Default::default(),
};
let config = Configuration { digest_interval: 4, digest_levels: 2 };
@@ -587,6 +587,7 @@ mod tests {
].into_iter().collect(),
committed: Default::default(),
collect_extrinsics: true,
stats: Default::default(),
}
}
@@ -20,6 +20,7 @@ use crate::{
StorageKey, StorageValue, StorageCollection,
trie_backend::TrieBackend,
backend::{Backend, insert_into_memory_db},
stats::UsageInfo,
};
use std::{error, fmt, collections::{BTreeMap, HashMap}, marker::PhantomData, ops};
use hash_db::Hasher;
@@ -357,6 +358,12 @@ impl<H: Hasher> Backend<H> for InMemory<H> where H::Out: Codec {
self.trie = Some(TrieBackend::new(mdb, root));
self.trie.as_ref()
}
fn register_overlay_stats(&mut self, _stats: &crate::stats::StateMachineStats) { }
fn usage_info(&self) -> UsageInfo {
UsageInfo::empty()
}
}
#[cfg(test)]
+14 -4
View File
@@ -18,7 +18,7 @@
#![warn(missing_docs)]
use std::{fmt, result, collections::HashMap, panic::UnwindSafe, marker::PhantomData};
use std::{fmt, result, collections::HashMap, panic::UnwindSafe};
use log::{warn, trace};
use hash_db::Hasher;
use codec::{Decode, Encode, Codec};
@@ -73,7 +73,7 @@ pub use trie_backend_essence::{TrieBackendStorage, Storage};
pub use trie_backend::TrieBackend;
pub use error::{Error, ExecutionError};
pub use in_memory_backend::InMemory as InMemoryBackend;
pub use stats::{UsageInfo, UsageUnit};
pub use stats::{UsageInfo, UsageUnit, StateMachineStats};
pub use sp_core::traits::CloneableSpawn;
type CallResult<R, E> = Result<NativeOrEncoded<R>, E>;
@@ -189,9 +189,19 @@ pub struct StateMachine<'a, B, H, N, Exec>
overlay: &'a mut OverlayedChanges,
extensions: Extensions,
changes_trie_state: Option<ChangesTrieState<'a, H, N>>,
_marker: PhantomData<(H, N)>,
storage_transaction_cache: Option<&'a mut StorageTransactionCache<B::Transaction, H, N>>,
runtime_code: &'a RuntimeCode<'a>,
stats: StateMachineStats,
}
impl<'a, B, H, N, Exec> Drop for StateMachine<'a, B, H, N, Exec> where
H: Hasher,
B: Backend<H>,
N: ChangesTrieBlockNumber,
{
fn drop(&mut self) {
self.backend.register_overlay_stats(&self.stats);
}
}
impl<'a, B, H, N, Exec> StateMachine<'a, B, H, N, Exec> where
@@ -224,9 +234,9 @@ impl<'a, B, H, N, Exec> StateMachine<'a, B, H, N, Exec> where
extensions,
overlay,
changes_trie_state,
_marker: PhantomData,
storage_transaction_cache: None,
runtime_code,
stats: StateMachineStats::default(),
}
}
@@ -22,6 +22,7 @@ use crate::{
NO_EXTRINSIC_INDEX, BlockNumber, build_changes_trie,
State as ChangesTrieState,
},
stats::StateMachineStats,
};
#[cfg(test)]
@@ -57,6 +58,8 @@ pub struct OverlayedChanges {
pub(crate) committed: OverlayedChangeSet,
/// True if extrinsics stats must be collected.
pub(crate) collect_extrinsics: bool,
/// Collect statistic on this execution.
pub(crate) stats: StateMachineStats,
}
/// The storage value, used inside OverlayedChanges.
@@ -206,7 +209,11 @@ impl OverlayedChanges {
pub fn storage(&self, key: &[u8]) -> Option<Option<&[u8]>> {
self.prospective.top.get(key)
.or_else(|| self.committed.top.get(key))
.map(|x| x.value.as_ref().map(AsRef::as_ref))
.map(|x| {
let size_read = x.value.as_ref().map(|x| x.len() as u64).unwrap_or(0);
self.stats.tally_read_modified(size_read);
x.value.as_ref().map(AsRef::as_ref)
})
}
/// Returns a double-Option: None if the key is unknown (i.e. and the query should be referred
@@ -215,12 +222,16 @@ impl OverlayedChanges {
pub fn child_storage(&self, storage_key: &[u8], key: &[u8]) -> Option<Option<&[u8]>> {
if let Some(map) = self.prospective.children.get(storage_key) {
if let Some(val) = map.0.get(key) {
let size_read = val.value.as_ref().map(|x| x.len() as u64).unwrap_or(0);
self.stats.tally_read_modified(size_read);
return Some(val.value.as_ref().map(AsRef::as_ref));
}
}
if let Some(map) = self.committed.children.get(storage_key) {
if let Some(val) = map.0.get(key) {
let size_read = val.value.as_ref().map(|x| x.len() as u64).unwrap_or(0);
self.stats.tally_read_modified(size_read);
return Some(val.value.as_ref().map(AsRef::as_ref));
}
}
@@ -232,6 +243,8 @@ impl OverlayedChanges {
///
/// `None` can be used to delete a value specified by the given key.
pub(crate) fn set_storage(&mut self, key: StorageKey, val: Option<StorageValue>) {
let size_write = val.as_ref().map(|x| x.len() as u64).unwrap_or(0);
self.stats.tally_write_overlay(size_write);
let extrinsic_index = self.extrinsic_index();
let entry = self.prospective.top.entry(key).or_default();
entry.value = val;
@@ -252,6 +265,8 @@ impl OverlayedChanges {
key: StorageKey,
val: Option<StorageValue>,
) {
let size_write = val.as_ref().map(|x| x.len() as u64).unwrap_or(0);
self.stats.tally_write_overlay(size_write);
let extrinsic_index = self.extrinsic_index();
let map_entry = self.prospective.children.entry(storage_key)
.or_insert_with(|| (Default::default(), child_info.to_owned()));
@@ -283,6 +283,12 @@ impl<'a, S, H> Backend<H> for ProvingBackend<'a, S, H>
{
self.0.child_storage_root(storage_key, child_info, delta)
}
fn register_overlay_stats(&mut self, _stats: &crate::stats::StateMachineStats) { }
fn usage_info(&self) -> crate::stats::UsageInfo {
self.0.usage_info()
}
}
/// Create proof check backend.
@@ -17,6 +17,7 @@
//! Usage statistics for state db
use std::time::{Instant, Duration};
use std::cell::RefCell;
/// Measured count of operations and total bytes.
#[derive(Clone, Debug, Default)]
@@ -32,10 +33,19 @@ pub struct UsageUnit {
pub struct UsageInfo {
/// Read statistics (total).
pub reads: UsageUnit,
/// Write statistics.
/// Write statistics (total).
pub writes: UsageUnit,
/// Write trie nodes statistics.
pub nodes_writes: UsageUnit,
/// Write into cached state machine
/// change overlay.
pub overlay_writes: UsageUnit,
/// Removed trie nodes statistics.
pub removed_nodes: UsageUnit,
/// Cache read statistics.
pub cache_reads: UsageUnit,
/// Modified value read statistics.
pub modified_reads: UsageUnit,
/// Memory used.
pub memory: usize,
@@ -45,6 +55,35 @@ pub struct UsageInfo {
pub span: Duration,
}
/// Accumulated usage statistics specific to state machine
/// crate.
#[derive(Debug, Default, Clone)]
pub struct StateMachineStats {
/// Number of read query from runtime
/// that hit a modified value (in state
/// machine overlay).
pub reads_modified: RefCell<u64>,
/// Size in byte of read queries that
/// hit a modified value.
pub bytes_read_modified: RefCell<u64>,
/// Number of time a write operation
/// occurs into the state machine overlay.
pub writes_overlay: RefCell<u64>,
/// Size in bytes of the writes overlay
/// operation.
pub bytes_writes_overlay: RefCell<u64>,
}
impl StateMachineStats {
/// Accumulates some registered stats.
pub fn add(&self, other: &StateMachineStats) {
*self.reads_modified.borrow_mut() += *other.reads_modified.borrow();
*self.bytes_read_modified.borrow_mut() += *other.bytes_read_modified.borrow();
*self.writes_overlay.borrow_mut() += *other.writes_overlay.borrow();
*self.bytes_writes_overlay.borrow_mut() += *other.bytes_writes_overlay.borrow();
}
}
impl UsageInfo {
/// Empty statistics.
///
@@ -53,10 +92,34 @@ impl UsageInfo {
Self {
reads: UsageUnit::default(),
writes: UsageUnit::default(),
overlay_writes: UsageUnit::default(),
nodes_writes: UsageUnit::default(),
removed_nodes: UsageUnit::default(),
cache_reads: UsageUnit::default(),
modified_reads: UsageUnit::default(),
memory: 0,
started: Instant::now(),
span: Default::default(),
}
}
/// Add collected state machine to this state.
pub fn include_state_machine_states(&mut self, count: &StateMachineStats) {
self.modified_reads.ops += *count.reads_modified.borrow();
self.modified_reads.bytes += *count.bytes_read_modified.borrow();
self.overlay_writes.ops += *count.writes_overlay.borrow();
self.overlay_writes.bytes += *count.bytes_writes_overlay.borrow();
}
}
impl StateMachineStats {
/// Tally one read modified operation, of some length.
pub fn tally_read_modified(&self, data_bytes: u64) {
*self.reads_modified.borrow_mut() += 1;
*self.bytes_read_modified.borrow_mut() += data_bytes;
}
/// Tally one write overlay operation, of some length.
pub fn tally_write_overlay(&self, data_bytes: u64) {
*self.writes_overlay.borrow_mut() += 1;
*self.bytes_writes_overlay.borrow_mut() += data_bytes;
}
}
@@ -240,6 +240,12 @@ impl<S: TrieBackendStorage<H>, H: Hasher> Backend<H> for TrieBackend<S, H> where
fn as_trie_backend(&mut self) -> Option<&TrieBackend<Self::TrieBackendStorage, H>> {
Some(self)
}
fn register_overlay_stats(&mut self, _stats: &crate::stats::StateMachineStats) { }
fn usage_info(&self) -> crate::UsageInfo {
crate::UsageInfo::empty()
}
}
#[cfg(test)]