Skip to content

Commit

Permalink
Reproduce strange runtime slowdown
Browse files Browse the repository at this point in the history
In this commit, I add a benchmark which sends 150 blocks, where each
block contains 100 deploy code transaction.

The benchmark is implemented in two ways:

* on top of parameter estimator testbed
* on top of runtime tested

In the first case, I observe a very stage behavior, where at some point
block processsing times severely degrades.

To reproduce, checkout this commit and run

```console
$ cargo test --release --package runtime-params-estimator --lib --features required -- v2::fast --exact --nocapture
$ cargo test --release --package runtime-params-estimator --lib --features required -- v2::slow --exact --nocapture
```

Look for `Runtime::apply` lines in the output, they they tell you how
long it takes to process one apply.

In the `fast` case, every apply takes about 16ms for me. In the `slow`
case, apply start at about 30ms, but then abruptly go to 600ms
  • Loading branch information
matklad authored and mina86 committed Sep 7, 2021
1 parent 8e3fbd1 commit ab4ae83
Show file tree
Hide file tree
Showing 3 changed files with 88 additions and 15 deletions.
11 changes: 11 additions & 0 deletions Cargo.lock

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

3 changes: 3 additions & 0 deletions runtime/runtime-params-estimator/Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -32,7 +32,10 @@ near-store = { path = "../../core/store" }
near-primitives = { path = "../../core/primitives" }
near-test-contracts = { path = "../../runtime/near-test-contracts" }

tracing-span-tree = { git = "https://github.com/matklad/tracing-span-tree" }

testlib = { path = "../../test-utils/testlib" }
runtime-tester = { path = "../../test-utils/runtime-tester" }
state-viewer = { path = "../../test-utils/state-viewer" }
nearcore = { path = "../../nearcore" }
rocksdb = "0.16.0"
Expand Down
89 changes: 74 additions & 15 deletions runtime/runtime-params-estimator/src/v2.rs
Original file line number Diff line number Diff line change
@@ -1,16 +1,21 @@
mod support;

use std::convert::TryFrom;
use std::sync::Arc;
use std::time::Instant;

use near_crypto::{KeyType, SecretKey};
use genesis_populate::GenesisBuilder;
use near_crypto::{InMemorySigner, KeyType, SecretKey};
use near_primitives::account::{AccessKey, AccessKeyPermission, FunctionCallPermission};
use near_primitives::transaction::{
Action, AddKeyAction, CreateAccountAction, DeleteAccountAction, DeleteKeyAction,
DeployContractAction, FunctionCallAction, SignedTransaction, StakeAction, TransferAction,
};
use near_primitives::types::AccountId;
use near_store::create_store;
use nearcore::{get_store_path, load_config};
use rand::Rng;
use runtime_tester::{BlockConfig, NetworkConfig, Scenario, TransactionConfig};

use crate::testbed_runners::Config;
use crate::v2::support::{Ctx, GasCost};
Expand Down Expand Up @@ -299,11 +304,11 @@ fn action_deploy_contract_base(ctx: &mut Ctx) -> GasCost {
deploy_contract(ctx, code)
};

let base_cost = action_sir_receipt_creation(ctx);
// let base_cost = action_sir_receipt_creation(ctx);

let cost = total_cost - base_cost;
ctx.cached.action_deploy_contract_base = Some(cost.clone());
cost
// let cost = total_cost - base_cost;
// ctx.cached.action_deploy_contract_base = Some(cost.clone());
total_cost
}

fn action_deploy_contract_per_byte(ctx: &mut Ctx) -> GasCost {
Expand Down Expand Up @@ -393,23 +398,77 @@ fn action_function_call_per_byte(ctx: &mut Ctx) -> GasCost {
}

#[test]
fn smoke() {
fn slow() {
use crate::testbed_runners::GasMetric;
use nearcore::get_default_home;

let tempdir = tempfile::tempdir().unwrap();
let p = tempdir.path();

nearcore::init_configs(
p, None, None, None, 1, true, None, false, None, false, None, None, None,
);

let near_config = load_config(p);
let store = create_store(&get_store_path(p));
GenesisBuilder::from_config_and_store(p, Arc::new(near_config.genesis), store.clone())
.add_additional_accounts(200_000)
.build()
.unwrap()
.dump_state()
.unwrap();

let config = Config {
warmup_iters_per_block: 1,
iter_per_block: 2,
iter_per_block: 150,
active_accounts: 20000,
block_sizes: vec![100],
state_dump_path: get_default_home().into(),
state_dump_path: p.to_path_buf(),
metric: GasMetric::Time,
vm_kind: near_vm_runner::VMKind::Wasmer0,
metrics_to_measure: Some(vec![
"ActionFunctionCallBase".to_string(),
"ActionFunctionCallPerByte".to_string(),
]),
metrics_to_measure: Some(vec!["ActionDeployContractBase".to_string()]),
};

tracing_span_tree::enable_aggregated();
let mut ctx = Ctx::new(&config);
action_deploy_contract_base(&mut ctx);
}

#[test]
fn fast() {
let code = vec![92; 256];
let num_accounts = 200_000;
let block_size = 100;
let n_blocks = 150;

let seeds: Vec<String> = (0..num_accounts).map(|i| format!("test{}", i)).collect();
let accounts: Vec<AccountId> = seeds.iter().map(|id| id.parse().unwrap()).collect();

let mut s = Scenario {
network_config: NetworkConfig { seeds: seeds },
blocks: Vec::new(),
use_in_memory_store: false,
};
let table = run(config);
eprintln!("{}", table);

let mut i = 0;
for h in 0..n_blocks {
let mut block = BlockConfig::at_height((h + 1) as u64);
for _ in 0..block_size {
let signer_id = accounts[i].clone();
let receiver_id = signer_id.clone();
let signer =
InMemorySigner::from_seed(signer_id.clone(), KeyType::ED25519, signer_id.as_ref());
block.transactions.push(TransactionConfig {
nonce: i as u64,
signer_id,
receiver_id,
signer,
actions: vec![Action::DeployContract(DeployContractAction { code: code.clone() })],
});
i += 1;
}
s.blocks.push(block)
}

tracing_span_tree::enable_aggregated();
s.run().unwrap();
}

0 comments on commit ab4ae83

Please sign in to comment.