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

Add statistics to benchmarking-cli output #5250

Closed
pscott wants to merge 42 commits into from
Closed

Add statistics to benchmarking-cli output #5250

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
42 commits
Select commit Hold shift + click to select a range
18b0170
Try adding benchmark to runtime and exposit runtime-benchmarks
Mar 5, 2020
e2286bc
Registering state from overlay.
cheme Mar 6, 2020
660ed3d
fix
cheme Mar 6, 2020
89520b9
fix2
cheme Mar 6, 2020
1dd381f
Merge branch 'master' of https://github.com/paritytech/substrate into…
Mar 6, 2020
07da93a
Merge branch 'state-metrics' of https://github.com/cheme/substrate in…
Mar 6, 2020
ae340b5
WIP: add usage info stub functions; add InstantWithDefault
Mar 9, 2020
fc784f3
Add new method to InstantWithDefault
Mar 9, 2020
5873f57
Add sp-state-machine as optional in frame/benchmarking
Mar 9, 2020
2199777
Rename methods
Mar 9, 2020
5100dc3
add sp_stats crate
Mar 10, 2020
711a161
Update comments and typo
Mar 10, 2020
9490cb7
Add default-features = false for runtime-interface
Mar 10, 2020
fe22050
Replace instant with Duration; Make code compilable
Mar 10, 2020
71d2a7c
Add corret fn signatures
Mar 10, 2020
a6dd88d
Impl PassBy in runtime-interface
Mar 10, 2020
169da7a
Remove empty return of db_usage_info
Mar 10, 2020
850062b
Remove unimplemented code
Mar 10, 2020
003325b
call usage_info in benchmarking-cli
Mar 11, 2020
ae5c499
Add RefCell<UsageInfo> to BenchmarkingState
Mar 12, 2020
04371db
Merge branch 'scott_add_usage_info' of github.com:pscott/substrate in…
Mar 12, 2020
a1516be
Revert "call usage_info in benchmarking-cli"
Mar 12, 2020
a60a5da
Update try_borrow_mut's error logic
Mar 12, 2020
43b81b6
Add mut keyword to usage_info
Mar 12, 2020
bd96591
Add anti-pattern let _ to silence clippy's warning
Mar 12, 2020
c9db643
Clean code and update comments
Mar 12, 2020
987027b
Read bytes as u64 instead of usize
Mar 13, 2020
c412117
Add bytes as u64 instead of usize
Mar 13, 2020
0c4c653
Update unimplemented code
Mar 13, 2020
2a358ac
Revert "Merge branch 'state-metrics' of https://github.com/cheme/subs…
Mar 13, 2020
d4294c6
Merge branch 'master' of github.com:paritytech/substrate into scott_a…
Mar 18, 2020
eb76aed
Bump sp-stats version
Mar 18, 2020
c527103
Remove try_borrow()
Mar 19, 2020
c00369b
Update memory to field to be u64 instead of u32
Mar 19, 2020
ac8c8dd
Explain sp-stats' purpose
Mar 19, 2020
8f749f8
Remove unimplemented wipe
Mar 19, 2020
3407c07
Merge branch 'master' of github.com:paritytech/substrate into scott_a…
Mar 28, 2020
ebc26e1
Correctly track state read / writes; Remove cache_hits
Mar 29, 2020
774527e
Update Cargo.lock
shawntabrizi Mar 29, 2020
1727792
Merge branch 'master' into scott_add_usage_info
pscott Mar 31, 2020
3d65985
Review merge
Mar 31, 2020
b8197bf
Unexpose benchmarking pallet
Mar 31, 2020
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
14 changes: 14 additions & 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 Cargo.toml
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -151,6 +151,7 @@ members = [
"primitives/std",
"primitives/version",
"primitives/state-machine",
"primitives/stats",
"primitives/timestamp",
"primitives/test-primitives",
"primitives/transaction-pool",
Expand Down
2 changes: 2 additions & 0 deletions bin/node/runtime/Cargo.toml
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -42,6 +42,7 @@ pallet-authority-discovery = { version = "2.0.0-alpha.5", default-features = fal
pallet-authorship = { version = "2.0.0-alpha.5", default-features = false, path = "../../../frame/authorship" }
pallet-babe = { version = "2.0.0-alpha.5", default-features = false, path = "../../../frame/babe" }
pallet-balances = { version = "2.0.0-alpha.5", default-features = false, path = "../../../frame/balances" }
pallet-benchmark = { version = "2.0.0-alpha.5", default-features = false, path = "../../../frame/benchmark" }
pallet-collective = { version = "2.0.0-alpha.5", default-features = false, path = "../../../frame/collective" }
pallet-contracts = { version = "2.0.0-alpha.5", default-features = false, path = "../../../frame/contracts" }
pallet-contracts-primitives = { version = "2.0.0-alpha.5", default-features = false, path = "../../../frame/contracts/common/" }
Expand Down Expand Up @@ -96,6 +97,7 @@ std = [
"frame-executive/std",
"pallet-finality-tracker/std",
"pallet-grandpa/std",
"pallet-benchmark/std",
"pallet-im-online/std",
"pallet-indices/std",
"sp-inherents/std",
Expand Down
1 change: 1 addition & 0 deletions client/Cargo.toml
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,7 @@ sp-blockchain = { version = "2.0.0-alpha.5", path = "../primitives/blockchain" }
sp-state-machine = { version = "0.8.0-alpha.5", path = "../primitives/state-machine" }
sc-telemetry = { version = "2.0.0-alpha.5", path = "telemetry" }
sp-trie = { version = "2.0.0-alpha.5", path = "../primitives/trie" }
sp-stats = { version = "2.0.0-alpha.5", path = "../primitives/stats" }
prometheus-endpoint = { package = "substrate-prometheus-endpoint", version = "0.8.0-alpha.5", path = "../utils/prometheus" }
tracing = "0.1.10"

Expand Down
1 change: 1 addition & 0 deletions client/db/Cargo.toml
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -25,6 +25,7 @@ sp-core = { version = "2.0.0-alpha.5", path = "../../primitives/core" }
sp-runtime = { version = "2.0.0-alpha.5", path = "../../primitives/runtime" }
sc-client = { version = "0.8.0-alpha.5", path = "../" }
sp-state-machine = { version = "0.8.0-alpha.5", path = "../../primitives/state-machine" }
sp-stats = { version = "2.0.0-alpha.5", path = "../../primitives/stats" }
sc-executor = { version = "0.8.0-alpha.5", path = "../executor" }
sc-state-db = { version = "0.8.0-alpha.5", path = "../state-db" }
sp-trie = { version = "2.0.0-alpha.5", path = "../../primitives/trie" }
Expand Down
31 changes: 29 additions & 2 deletions client/db/src/bench.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -29,6 +29,8 @@ use sp_runtime::Storage;
use sp_state_machine::{DBValue, backend::Backend as StateBackend};
use kvdb::{KeyValueDB, DBTransaction};
use kvdb_rocksdb::{Database, DatabaseConfig};
use crate::stats::StateUsageStats;
use sp_stats::UsageInfo;

type DbState<B> = sp_state_machine::TrieBackend<
Arc<dyn sp_state_machine::Storage<HashFor<B>>>, HashFor<B>
Expand All @@ -55,6 +57,7 @@ pub struct BenchmarkingState<B: BlockT> {
state: RefCell<Option<DbState<B>>>,
db: Cell<Option<Arc<dyn KeyValueDB>>>,
genesis: <DbState<B> as StateBackend<HashFor<B>>>::Transaction,
state_usage_stats: StateUsageStats,
}

impl<B: BlockT> BenchmarkingState<B> {
Expand All @@ -76,6 +79,7 @@ impl<B: BlockT> BenchmarkingState<B> {
root: Cell::new(root),
genesis: Default::default(),
genesis_root: Default::default(),
state_usage_stats: StateUsageStats::new(),
};

state.reopen()?;
Expand Down Expand Up @@ -135,7 +139,11 @@ impl<B: BlockT> StateBackend<HashFor<B>> for BenchmarkingState<B> {
type TrieBackendStorage = <DbState<B> as StateBackend<HashFor<B>>>::TrieBackendStorage;

fn storage(&self, key: &[u8]) -> Result<Option<Vec<u8>>, Self::Error> {
self.state.borrow().as_ref().ok_or_else(state_err)?.storage(key)
let state = self.state.borrow_mut();
let db_state = state.as_ref().ok_or_else(state_err)?;
let value = db_state.storage(key)?;
self.state_usage_stats.tally_key_read(key, value.as_ref(), false);
Ok(value)
}

fn storage_hash(&self, key: &[u8]) -> Result<Option<B::Hash>, Self::Error> {
Expand All @@ -148,7 +156,12 @@ impl<B: BlockT> StateBackend<HashFor<B>> for BenchmarkingState<B> {
child_info: ChildInfo,
key: &[u8],
) -> Result<Option<Vec<u8>>, Self::Error> {
self.state.borrow().as_ref().ok_or_else(state_err)?.child_storage(storage_key, child_info, key)
let db_state = self.state.borrow();
let db_state_ref = db_state.as_ref().ok_or_else(state_err)?;
let value = db_state_ref.child_storage(storage_key, child_info, key)?;
let key = (storage_key.to_vec(), key.to_vec());
let value = self.state_usage_stats.tally_child_key_read(&key, value, false);
Ok(value)
}

fn exists_storage(&self, key: &[u8]) -> Result<bool, Self::Error> {
Expand Down Expand Up @@ -257,15 +270,25 @@ impl<B: BlockT> StateBackend<HashFor<B>> for BenchmarkingState<B> {
{
if let Some(db) = self.db.take() {
let mut db_transaction = DBTransaction::new();
let mut ops: u64 = 0;
let mut bytes: u64 = 0;

for (key, (val, rc)) in transaction.drain() {
if rc > 0 {
ops += 1;
bytes += key.len() as u64 + val.len() as u64;

db_transaction.put(0, &key, &val);
} else if rc < 0 {
ops += 1;
bytes += key.len() as u64;

db_transaction.delete(0, &key);
}
}
self.state_usage_stats.tally_writes(ops, bytes);
db.write(db_transaction).map_err(|_| String::from("Error committing transaction"))?;

self.root.set(storage_root);
} else {
return Err("Trying to commit to a closed db".into())
Expand All @@ -279,6 +302,10 @@ impl<B: BlockT> StateBackend<HashFor<B>> for BenchmarkingState<B> {
self.commit(self.genesis_root.clone(), self.genesis.clone())?;
Ok(())
}

fn usage_info(&self) -> UsageInfo {
self.state_usage_stats.take()
}
}

impl<Block: BlockT> std::fmt::Debug for BenchmarkingState<Block> {
Expand Down
3 changes: 2 additions & 1 deletion client/db/src/lib.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -71,10 +71,11 @@ use sp_runtime::traits::{
};
use sc_executor::RuntimeInfo;
use sp_state_machine::{
DBValue, ChangesTrieTransaction, ChangesTrieCacheAction, UsageInfo as StateUsageInfo,
DBValue, ChangesTrieTransaction, ChangesTrieCacheAction,
StorageCollection, ChildStorageCollection,
backend::Backend as StateBackend,
};
use sp_stats::{UsageInfo as StateUsageInfo};
use crate::utils::{DatabaseType, Meta, db_err, meta_keys, read_db, read_meta};
use crate::changes_tries_storage::{DbChangesTrieStorage, DbChangesTrieStorageTransaction};
use sc_client::leaves::{LeafSet, FinalizationDisplaced};
Expand Down
12 changes: 7 additions & 5 deletions client/db/src/stats.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,7 @@
//! Database usage statistics

use std::sync::atomic::{AtomicU64, Ordering as AtomicOrdering};
use std::time::{SystemTime, UNIX_EPOCH};

/// Accumulated usage statistics for state queries.
pub struct StateUsageStats {
Expand Down Expand Up @@ -77,7 +78,7 @@ impl StateUsageStats {
}

/// Merge state machine usage info.
pub fn merge_sm(&self, info: sp_state_machine::UsageInfo) {
Copy link
Contributor

@NikVolf NikVolf Mar 31, 2020

Choose a reason for hiding this comment

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

is this something you changed @pscott
or it was part of @cheme merged pr?

pub fn merge_sm(&self, info: sp_stats::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);
Expand All @@ -87,8 +88,8 @@ impl StateUsageStats {
}

/// Returns the collected `UsageInfo` and resets the internal state.
pub fn take(&self) -> sp_state_machine::UsageInfo {
use sp_state_machine::UsageUnit;
pub fn take(&self) -> sp_stats::UsageInfo {
use sp_stats::UsageUnit;

fn unit(ops: &AtomicU64, bytes: &AtomicU64) -> UsageUnit {
UsageUnit {
Expand All @@ -97,15 +98,16 @@ impl StateUsageStats {
}
}

sp_state_machine::UsageInfo {
sp_stats::UsageInfo {
reads: unit(&self.reads, &self.bytes_read),
writes: unit(&self.writes, &self.bytes_written),
cache_reads: unit(&self.reads_cache, &self.bytes_read_cache),
// 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
memory: 0,
started: self.started,
// expect?
started: SystemTime::now().duration_since(UNIX_EPOCH).expect("Time went backwards"),
span: self.started.elapsed(),
}
}
Expand Down
4 changes: 2 additions & 2 deletions client/db/src/storage_cache.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -663,7 +663,7 @@ impl<S: StateBackend<HashFor<B>>, B: BlockT> StateBackend<HashFor<B>> for Cachin
self.state.as_trie_backend()
}

fn usage_info(&self) -> sp_state_machine::UsageInfo {
fn usage_info(&self) -> sp_stats::UsageInfo {
self.usage.take()
}
}
Expand Down Expand Up @@ -852,7 +852,7 @@ impl<S: StateBackend<HashFor<B>>, B: BlockT> StateBackend<HashFor<B>> for Syncin
.as_trie_backend()
}

fn usage_info(&self) -> sp_state_machine::UsageInfo {
fn usage_info(&self) -> sp_stats::UsageInfo {
self.caching_state().usage_info()
}
}
Expand Down
3 changes: 3 additions & 0 deletions frame/benchmarking/Cargo.toml
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -15,10 +15,12 @@ sp-api = { version = "2.0.0-alpha.5", path = "../../primitives/api", default-fea
sp-runtime-interface = { version = "2.0.0-alpha.5", path = "../../primitives/runtime-interface", default-features = false }
sp-runtime = { version = "2.0.0-alpha.5", path = "../../primitives/runtime", default-features = false }
sp-std = { version = "2.0.0-alpha.5", path = "../../primitives/std", default-features = false }
sp-stats = { version = "2.0.0-alpha.5", path = "../../primitives/stats", default-features = false }
sp-io = { path = "../../primitives/io", default-features = false, version = "2.0.0-alpha.5"}
frame-support = { version = "2.0.0-alpha.5", default-features = false, path = "../support" }
frame-system = { version = "2.0.0-alpha.5", default-features = false, path = "../system" }


[features]
default = [ "std" ]
std = [
Expand All @@ -27,6 +29,7 @@ std = [
"sp-runtime/std",
"sp-api/std",
"sp-std/std",
"sp-stats/std",
"frame-support/std",
"frame-system/std",
]
Expand Down
38 changes: 19 additions & 19 deletions frame/benchmarking/src/analysis.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -32,7 +32,7 @@ impl Analysis {
pub fn median_slopes(r: &Vec<BenchmarkResults>) -> Option<Self> {
let results = r[0].0.iter().enumerate().map(|(i, &(param, _))| {
let mut counted = BTreeMap::<Vec<u32>, usize>::new();
for (params, _, _) in r.iter() {
for (params, _, _, _, _) in r.iter() {
let mut p = params.iter().map(|x| x.1).collect::<Vec<_>>();
p[i] = 0;
*counted.entry(p).or_default() += 1;
Expand All @@ -45,7 +45,7 @@ impl Analysis {
.zip(others.iter())
.enumerate()
.all(|(j, (v1, v2))| j == i || v1 == *v2)
).map(|(ps, v, _)| (ps[i].1, *v))
).map(|(ps, v, _, _, _)| (ps[i].1, *v))
.collect::<Vec<_>>();
(format!("{:?}", param), i, others, values)
}).collect::<Vec<_>>();
Expand Down Expand Up @@ -98,7 +98,7 @@ impl Analysis {

pub fn min_squares_iqr(r: &Vec<BenchmarkResults>) -> Option<Self> {
let mut results = BTreeMap::<Vec<u32>, Vec<u128>>::new();
for &(ref params, t, _) in r.iter() {
for &(ref params, t, _, _, _) in r.iter() {
let p = params.iter().map(|x| x.1).collect::<Vec<_>>();
results.entry(p).or_default().push(t);
}
Expand Down Expand Up @@ -212,14 +212,14 @@ mod tests {
#[test]
fn analysis_median_slopes_should_work() {
let a = Analysis::median_slopes(&vec![
(vec![(BenchmarkParameter::n, 1), (BenchmarkParameter::m, 5)], 11_500_000, 0),
(vec![(BenchmarkParameter::n, 2), (BenchmarkParameter::m, 5)], 12_500_000, 0),
(vec![(BenchmarkParameter::n, 3), (BenchmarkParameter::m, 5)], 13_500_000, 0),
(vec![(BenchmarkParameter::n, 4), (BenchmarkParameter::m, 5)], 14_500_000, 0),
(vec![(BenchmarkParameter::n, 3), (BenchmarkParameter::m, 1)], 13_100_000, 0),
(vec![(BenchmarkParameter::n, 3), (BenchmarkParameter::m, 3)], 13_300_000, 0),
(vec![(BenchmarkParameter::n, 3), (BenchmarkParameter::m, 7)], 13_700_000, 0),
(vec![(BenchmarkParameter::n, 3), (BenchmarkParameter::m, 10)], 14_000_000, 0),
(vec![(BenchmarkParameter::n, 1), (BenchmarkParameter::m, 5)], 11_500_000, 0, 0, 0),
(vec![(BenchmarkParameter::n, 2), (BenchmarkParameter::m, 5)], 12_500_000, 0, 0, 0),
(vec![(BenchmarkParameter::n, 3), (BenchmarkParameter::m, 5)], 13_500_000, 0, 0, 0),
(vec![(BenchmarkParameter::n, 4), (BenchmarkParameter::m, 5)], 14_500_000, 0, 0, 0),
(vec![(BenchmarkParameter::n, 3), (BenchmarkParameter::m, 1)], 13_100_000, 0, 0, 0),
(vec![(BenchmarkParameter::n, 3), (BenchmarkParameter::m, 3)], 13_300_000, 0, 0, 0),
(vec![(BenchmarkParameter::n, 3), (BenchmarkParameter::m, 7)], 13_700_000, 0, 0, 0),
(vec![(BenchmarkParameter::n, 3), (BenchmarkParameter::m, 10)], 14_000_000, 0, 0, 0),
]).unwrap();
assert_eq!(a.base, 10_000_000);
assert_eq!(a.slopes, vec![1_000_000, 100_000]);
Expand All @@ -228,14 +228,14 @@ mod tests {
#[test]
fn analysis_median_min_squares_should_work() {
let a = Analysis::min_squares_iqr(&vec![
(vec![(BenchmarkParameter::n, 1), (BenchmarkParameter::m, 5)], 11_500_000, 0),
(vec![(BenchmarkParameter::n, 2), (BenchmarkParameter::m, 5)], 12_500_000, 0),
(vec![(BenchmarkParameter::n, 3), (BenchmarkParameter::m, 5)], 13_500_000, 0),
(vec![(BenchmarkParameter::n, 4), (BenchmarkParameter::m, 5)], 14_500_000, 0),
(vec![(BenchmarkParameter::n, 3), (BenchmarkParameter::m, 1)], 13_100_000, 0),
(vec![(BenchmarkParameter::n, 3), (BenchmarkParameter::m, 3)], 13_300_000, 0),
(vec![(BenchmarkParameter::n, 3), (BenchmarkParameter::m, 7)], 13_700_000, 0),
(vec![(BenchmarkParameter::n, 3), (BenchmarkParameter::m, 10)], 14_000_000, 0),
(vec![(BenchmarkParameter::n, 1), (BenchmarkParameter::m, 5)], 11_500_000, 0, 0, 0),
(vec![(BenchmarkParameter::n, 2), (BenchmarkParameter::m, 5)], 12_500_000, 0, 0, 0),
(vec![(BenchmarkParameter::n, 3), (BenchmarkParameter::m, 5)], 13_500_000, 0, 0, 0),
(vec![(BenchmarkParameter::n, 4), (BenchmarkParameter::m, 5)], 14_500_000, 0, 0, 0),
(vec![(BenchmarkParameter::n, 3), (BenchmarkParameter::m, 1)], 13_100_000, 0, 0, 0),
(vec![(BenchmarkParameter::n, 3), (BenchmarkParameter::m, 3)], 13_300_000, 0, 0, 0),
(vec![(BenchmarkParameter::n, 3), (BenchmarkParameter::m, 7)], 13_700_000, 0, 0, 0),
(vec![(BenchmarkParameter::n, 3), (BenchmarkParameter::m, 10)], 14_000_000, 0, 0, 0),
]).unwrap();
assert_eq!(a.base, 10_000_000);
assert_eq!(a.slopes, vec![1_000_000, 100_000]);
Expand Down
6 changes: 4 additions & 2 deletions frame/benchmarking/src/lib.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -585,8 +585,9 @@ macro_rules! impl_benchmark {
$crate::storage_root();
let finish_storage_root = $crate::benchmarking::current_time();
let elapsed_storage_root = finish_storage_root - start_storage_root;
let usage_info = $crate::benchmarking::db_usage_info();

results.push((c.clone(), elapsed_extrinsic, elapsed_storage_root));
results.push((c.clone(), elapsed_extrinsic, elapsed_storage_root, usage_info.reads.ops, usage_info.writes.ops));

// Wipe the DB back to the genesis state.
$crate::benchmarking::wipe_db();
Expand Down Expand Up @@ -681,8 +682,9 @@ macro_rules! impl_benchmark {
$crate::storage_root();
let finish_storage_root = $crate::benchmarking::current_time();
let elapsed_storage_root = finish_storage_root - start_storage_root;
let usage_info = $crate::benchmarking::db_usage_info();

results.push((c.clone(), elapsed_extrinsic, elapsed_storage_root));
results.push((c.clone(), elapsed_extrinsic, elapsed_storage_root, usage_info.reads.ops, usage_info.writes.ops));

// Wipe the DB back to the genesis state.
$crate::benchmarking::wipe_db();
Expand Down
Loading