Nbench - Flexible benchmarking of Nimbus internals (#641)

* nbench PoC * Remove the yaml files from the example scenarios * update README with current status * Add an alternative implementation that uses defer * Forgot to add the old proc body * slots-processing * allow benching state_transition failures * Add Attestations processing (workaround confutils bug: - status-im/nim-confutils#10 - status-im/nim-confutils#11 - status-im/nim-confutils#12 * Add CLI command in the readme * Filter report and add notes about CPU cycles * Report averages * Add debugecho style time/cycle print * Report when we skip BLS and state root verification * Update to 0.9.3 * Generalize scenario parsing * Support all block processing scenarios * parallel bench runner PoC * gitBetter load issues reporting (the load issues were invalid signature and expected to fail)
status-im · Dec 20, 2019 · 106352a · 106352a
1 parent 417f962
commit 106352a
Show file tree

Hide file tree

Showing 14 changed files with 809 additions and 32 deletions.
diff --git a/beacon_chain/spec/beaconstate.nim b/beacon_chain/spec/beaconstate.nim
@@ -9,10 +9,11 @@ import
   tables, algorithm, math, sequtils, options,
   json_serialization/std/sets, chronicles, stew/bitseqs,
   ../extras, ../ssz,
-  ./crypto, ./datatypes, ./digest, ./helpers, ./validator
+  ./crypto, ./datatypes, ./digest, ./helpers, ./validator,
+  ../../nbench/bench_lab
 
 # https://github.com/ethereum/eth2.0-specs/blob/v0.9.3/specs/core/0_beacon-chain.md#is_valid_merkle_branch
-func is_valid_merkle_branch*(leaf: Eth2Digest, branch: openarray[Eth2Digest], depth: uint64, index: uint64, root: Eth2Digest): bool =
+func is_valid_merkle_branch*(leaf: Eth2Digest, branch: openarray[Eth2Digest], depth: uint64, index: uint64, root: Eth2Digest): bool {.nbench.}=
   ## Check if ``leaf`` at ``index`` verifies against the Merkle ``root`` and
   ## ``branch``.
   var
@@ -48,7 +49,7 @@ func decrease_balance*(
 
 # https://github.com/ethereum/eth2.0-specs/blob/v0.8.4/specs/core/0_beacon-chain.md#deposits
 func process_deposit*(
-    state: var BeaconState, deposit: Deposit, flags: UpdateFlags = {}): bool =
+    state: var BeaconState, deposit: Deposit, flags: UpdateFlags = {}): bool {.nbench.}=
   # Process an Eth1 deposit, registering a validator or increasing its balance.
 
   # Verify the Merkle branch
@@ -194,7 +195,7 @@ func initialize_beacon_state_from_eth1*(
     eth1_block_hash: Eth2Digest,
     eth1_timestamp: uint64,
     deposits: openArray[Deposit],
-    flags: UpdateFlags = {}): BeaconState =
+    flags: UpdateFlags = {}): BeaconState {.nbench.}=
   ## Get the genesis ``BeaconState``.
   ##
   ## Before the beacon chain starts, validators will register in the Eth1 chain
@@ -315,7 +316,7 @@ func is_eligible_for_activation(state: BeaconState, validator: Validator):
     validator.activation_epoch == FAR_FUTURE_EPOCH
 
 # https://github.com/ethereum/eth2.0-specs/blob/v0.9.3/specs/core/0_beacon-chain.md#registry-updates
-proc process_registry_updates*(state: var BeaconState) =
+proc process_registry_updates*(state: var BeaconState) {.nbench.}=
   ## Process activation eligibility and ejections
   ## Try to avoid caching here, since this could easily become undefined
 
@@ -500,7 +501,7 @@ proc check_attestation*(
 
 proc process_attestation*(
     state: var BeaconState, attestation: Attestation, flags: UpdateFlags,
-    stateCache: var StateCache): bool =
+    stateCache: var StateCache): bool {.nbench.}=
   # In the spec, attestation validation is mixed with state mutation, so here
   # we've split it into two functions so that the validation logic can be
   # reused when looking for suitable blocks to include in attestations.

diff --git a/beacon_chain/spec/state_transition_block.nim b/beacon_chain/spec/state_transition_block.nim
@@ -35,7 +35,8 @@
 import
   algorithm, collections/sets, chronicles, options, sequtils, sets, tables,
   ../extras, ../ssz, metrics,
-  beaconstate, crypto, datatypes, digest, helpers, validator
+  beaconstate, crypto, datatypes, digest, helpers, validator,
+  ../../nbench/bench_lab
 
 # https://github.com/ethereum/eth2.0-metrics/blob/master/metrics.md#additional-metrics
 declareGauge beacon_current_live_validators, "Number of active validators that successfully included attestation on chain for current epoch" # On block
@@ -46,7 +47,7 @@ declareGauge beacon_processed_deposits_total, "Number of total deposits included
 # https://github.com/ethereum/eth2.0-specs/blob/v0.9.3/specs/core/0_beacon-chain.md#block-header
 proc process_block_header*(
     state: var BeaconState, blck: BeaconBlock, flags: UpdateFlags,
-    stateCache: var StateCache): bool =
+    stateCache: var StateCache): bool {.nbench.}=
   # Verify that the slots match
   if not (blck.slot == state.slot):
     notice "Block header: slot mismatch",
@@ -89,7 +90,7 @@ proc process_block_header*(
 # https://github.com/ethereum/eth2.0-specs/blob/v0.9.2/specs/core/0_beacon-chain.md#randao
 proc process_randao(
     state: var BeaconState, body: BeaconBlockBody, flags: UpdateFlags,
-    stateCache: var StateCache): bool =
+    stateCache: var StateCache): bool {.nbench.}=
   let
     epoch = state.get_current_epoch()
     proposer_index = get_beacon_proposer_index(state, stateCache)
@@ -125,7 +126,7 @@ proc process_randao(
   true
 
 # https://github.com/ethereum/eth2.0-specs/blob/v0.9.3/specs/core/0_beacon-chain.md#eth1-data
-func process_eth1_data(state: var BeaconState, body: BeaconBlockBody) =
+func process_eth1_data(state: var BeaconState, body: BeaconBlockBody) {.nbench.}=
   state.eth1_data_votes.add body.eth1_data
   if state.eth1_data_votes.count(body.eth1_data) * 2 >
       SLOTS_PER_ETH1_VOTING_PERIOD:
@@ -141,7 +142,7 @@ func is_slashable_validator(validator: Validator, epoch: Epoch): bool =
 # https://github.com/ethereum/eth2.0-specs/blob/v0.9.3/specs/core/0_beacon-chain.md#proposer-slashings
 proc process_proposer_slashing*(
     state: var BeaconState, proposer_slashing: ProposerSlashing,
-    flags: UpdateFlags, stateCache: var StateCache): bool =
+    flags: UpdateFlags, stateCache: var StateCache): bool {.nbench.}=
   if proposer_slashing.proposer_index.int >= state.validators.len:
     notice "Proposer slashing: invalid proposer index"
     return false
@@ -187,7 +188,7 @@ proc process_proposer_slashing*(
 
 proc processProposerSlashings(
     state: var BeaconState, blck: BeaconBlock, flags: UpdateFlags,
-    stateCache: var StateCache): bool =
+    stateCache: var StateCache): bool {.nbench.}=
   if len(blck.body.proposer_slashings) > MAX_PROPOSER_SLASHINGS:
     notice "PropSlash: too many!",
       proposer_slashings = len(blck.body.proposer_slashings)
@@ -217,7 +218,7 @@ proc process_attester_slashing*(
        state: var BeaconState,
        attester_slashing: AttesterSlashing,
        stateCache: var StateCache
-     ): bool =
+     ): bool {.nbench.}=
     let
       attestation_1 = attester_slashing.attestation_1
       attestation_2 = attester_slashing.attestation_2
@@ -251,7 +252,7 @@ proc process_attester_slashing*(
 
 # https://github.com/ethereum/eth2.0-specs/blob/v0.9.3/specs/core/0_beacon-chain.md#attester-slashings
 proc processAttesterSlashings(state: var BeaconState, blck: BeaconBlock,
-    stateCache: var StateCache): bool =
+    stateCache: var StateCache): bool {.nbench.}=
   # Process ``AttesterSlashing`` operation.
   if len(blck.body.attester_slashings) > MAX_ATTESTER_SLASHINGS:
     notice "Attester slashing: too many!"
@@ -265,7 +266,7 @@ proc processAttesterSlashings(state: var BeaconState, blck: BeaconBlock,
 # https://github.com/ethereum/eth2.0-specs/blob/v0.8.4/specs/core/0_beacon-chain.md#attestations
 proc processAttestations(
     state: var BeaconState, blck: BeaconBlock, flags: UpdateFlags,
-    stateCache: var StateCache): bool =
+    stateCache: var StateCache): bool {.nbench.}=
   ## Each block includes a number of attestations that the proposer chose. Each
   ## attestation represents an update to a specific shard and is signed by a
   ## committee of validators.
@@ -285,7 +286,7 @@ proc processAttestations(
   true
 
 # https://github.com/ethereum/eth2.0-specs/blob/v0.8.4/specs/core/0_beacon-chain.md#deposits
-proc processDeposits(state: var BeaconState, blck: BeaconBlock): bool =
+proc processDeposits(state: var BeaconState, blck: BeaconBlock): bool {.nbench.}=
   if not (len(blck.body.deposits) <= MAX_DEPOSITS):
     notice "processDeposits: too many deposits"
     return false
@@ -301,7 +302,7 @@ proc processDeposits(state: var BeaconState, blck: BeaconBlock): bool =
 proc process_voluntary_exit*(
     state: var BeaconState,
     signed_voluntary_exit: SignedVoluntaryExit,
-    flags: UpdateFlags): bool =
+    flags: UpdateFlags): bool {.nbench.}=
 
   let voluntary_exit = signed_voluntary_exit.message
 
@@ -361,7 +362,7 @@ proc process_voluntary_exit*(
 
   true
 
-proc processVoluntaryExits(state: var BeaconState, blck: BeaconBlock, flags: UpdateFlags): bool =
+proc processVoluntaryExits(state: var BeaconState, blck: BeaconBlock, flags: UpdateFlags): bool {.nbench.}=
   if len(blck.body.voluntary_exits) > MAX_VOLUNTARY_EXITS:
     notice "[Block processing - Voluntary Exit]: too many exits!"
     return false
@@ -372,7 +373,7 @@ proc processVoluntaryExits(state: var BeaconState, blck: BeaconBlock, flags: Upd
 
 proc processBlock*(
     state: var BeaconState, blck: BeaconBlock, flags: UpdateFlags,
-    stateCache: var StateCache): bool =
+    stateCache: var StateCache): bool {.nbench.}=
   ## When there's a new block, we need to verify that the block is sane and
   ## update the state accordingly
 

diff --git a/beacon_chain/spec/state_transition_epoch.nim b/beacon_chain/spec/state_transition_epoch.nim
@@ -37,7 +37,8 @@ import
   stew/[bitseqs, bitops2], chronicles, json_serialization/std/sets,
   metrics, ../ssz,
   beaconstate, crypto, datatypes, digest, helpers, validator,
-  state_transition_helpers
+  state_transition_helpers,
+  ../../nbench/bench_lab
 
 # Logging utilities
 # --------------------------------------------------------
@@ -102,7 +103,7 @@ func get_attesting_balance(
 
 # https://github.com/ethereum/eth2.0-specs/blob/v0.9.3/specs/core/0_beacon-chain.md#justification-and-finalization
 proc process_justification_and_finalization*(
-    state: var BeaconState, stateCache: var StateCache) =
+    state: var BeaconState, stateCache: var StateCache) {.nbench.}=
 
   logScope: pcs = "process_justification_and_finalization"
 
@@ -243,7 +244,7 @@ func get_base_reward(state: BeaconState, index: ValidatorIndex,
 
 # https://github.com/ethereum/eth2.0-specs/blob/v0.9.2/specs/core/0_beacon-chain.md#rewards-and-penalties-1
 func get_attestation_deltas(state: BeaconState, stateCache: var StateCache):
-    tuple[a: seq[Gwei], b: seq[Gwei]] =
+    tuple[a: seq[Gwei], b: seq[Gwei]] {.nbench.}=
   let
     previous_epoch = get_previous_epoch(state)
     total_balance = get_total_active_balance(state)
@@ -339,7 +340,7 @@ func get_attestation_deltas(state: BeaconState, stateCache: var StateCache):
 
 # https://github.com/ethereum/eth2.0-specs/blob/v0.9.3/specs/core/0_beacon-chain.md#rewards-and-penalties-1
 func process_rewards_and_penalties(
-    state: var BeaconState, cache: var StateCache) =
+    state: var BeaconState, cache: var StateCache) {.nbench.}=
   if get_current_epoch(state) == GENESIS_EPOCH:
     return
 
@@ -367,7 +368,7 @@ func process_slashings*(state: var BeaconState) =
       decrease_balance(state, index.ValidatorIndex, penalty)
 
 # https://github.com/ethereum/eth2.0-specs/blob/v0.9.3/specs/core/0_beacon-chain.md#final-updates
-func process_final_updates*(state: var BeaconState) =
+func process_final_updates*(state: var BeaconState) {.nbench.}=
   let
     current_epoch = get_current_epoch(state)
     next_epoch = current_epoch + 1
@@ -407,7 +408,7 @@ func process_final_updates*(state: var BeaconState) =
   state.current_epoch_attestations = @[]
 
 # https://github.com/ethereum/eth2.0-specs/blob/v0.9.3/specs/core/0_beacon-chain.md#epoch-processing
-proc process_epoch*(state: var BeaconState) =
+proc process_epoch*(state: var BeaconState) {.nbench.}=
   # @proc are placeholders
 
   trace "process_epoch",

diff --git a/beacon_chain/state_transition.nim b/beacon_chain/state_transition.nim
@@ -34,7 +34,8 @@ import
   collections/sets, chronicles, sets,
   ./extras, ./ssz, metrics,
   ./spec/[datatypes, digest, helpers, validator],
-  ./spec/[state_transition_block, state_transition_epoch]
+  ./spec/[state_transition_block, state_transition_epoch],
+  ../nbench/bench_lab
 
 # https://github.com/ethereum/eth2.0-metrics/blob/master/metrics.md#additional-metrics
 declareGauge beacon_current_validators, """Number of status="pending|active|exited|withdrawable" validators in current epoch""" # On epoch transition
@@ -44,7 +45,7 @@ declareGauge beacon_previous_validators, """Number of status="pending|active|exi
 # ---------------------------------------------------------------
 
 # https://github.com/ethereum/eth2.0-specs/blob/v0.9.2/specs/core/0_beacon-chain.md#beacon-chain-state-transition-function
-func process_slot*(state: var BeaconState) =
+func process_slot*(state: var BeaconState) {.nbench.}=
   # Cache state root
   let previous_state_root = hash_tree_root(state)
   state.state_roots[state.slot mod SLOTS_PER_HISTORICAL_ROOT] =
@@ -81,7 +82,7 @@ func get_epoch_validator_count(state: BeaconState): int64 =
       result += 1
 
 # https://github.com/ethereum/eth2.0-specs/blob/v0.9.2/specs/core/0_beacon-chain.md#beacon-chain-state-transition-function
-proc process_slots*(state: var BeaconState, slot: Slot) =
+proc process_slots*(state: var BeaconState, slot: Slot) {.nbench.}=
   doAssert state.slot <= slot
 
   # Catch up to the target slot
@@ -108,7 +109,7 @@ proc verifyStateRoot(state: BeaconState, blck: BeaconBlock): bool =
     true
 
 proc state_transition*(
-    state: var BeaconState, blck: BeaconBlock, flags: UpdateFlags): bool =
+    state: var BeaconState, blck: BeaconBlock, flags: UpdateFlags): bool {.nbench.}=
   ## Time in the beacon chain moves by slots. Every time (haha.) that happens,
   ## we will update the beacon state. Normally, the state updates will be driven
   ## by the contents of a new block, but it may happen that the block goes

diff --git a/nbench/README.md b/nbench/README.md
@@ -0,0 +1,70 @@
+# Nimbus-bench
+
+Nbench is a profiler dedicated to the Nimbus Beacon Chain.
+
+It is built as a domain specific profiler that aims to be
+as unintrusive as possible while providing complementary reports
+to dedicated tools like ``perf``, ``Apple Instruments`` or ``Intel Vtune``
+that allows you to dive deep down to a specific line or assembly instructions.
+
+In particular, those tools cannot tell you that your cryptographic subsystem
+or your parsing routines or your random number generation should be revisited,
+may sample at to high a resolution (millisecond) instead of per-function statistics,
+and are much less useful without debugging symbols which requires a lot of space.
+I.e. ``perf`` and other generic profiler tools give you the laser-thin focused pictures
+while nbench strives to give you the big picture.
+
+Features
+- by default nbench will collect the number of calls and time spent in
+  each function.
+- like ncli or nfuzz, you can provide nbench isolated scenarios in SSZ format
+  to analyze Nimbus behaviour.
+
+## Usage
+
+```
+nim c -d:const_preset=mainnet -d:nbench -d:release -o:build/nbench nbench/nbench.nim
+export SCENARIOS=tests/official/fixtures/tests-v0.9.3/mainnet/phase0
+
+# Full state transition
+build/nbench cmdFullStateTransition -d="${SCENARIOS}"/sanity/blocks/pyspec_tests/voluntary_exit/ -q=2
+
+# Slot processing
+build/nbench cmdSlotProcessing -d="${SCENARIOS}"/sanity/slots/pyspec_tests/slots_1
+
+# Block header processing
+build/nbench cmdBlockProcessing --blockProcessingCat=catBlockHeader -d="${SCENARIOS}"/operations/block_header/pyspec_tests/proposer_slashed/
+
+# Proposer slashing
+build/nbench cmdBlockProcessing --blockProcessingCat=catProposerSlashings -d="${SCENARIOS}"/operations/proposer_slashing/pyspec_tests/invalid_proposer_index/
+
+# Attester slashing
+build/nbench cmdBlockProcessing --blockProcessingCat=catAttesterSlashings -d="${SCENARIOS}"/operations/attester_slashing/pyspec_tests/success_surround/
+
+# Attestation processing
+build/nbench cmdBlockProcessing --blockProcessingCat=catAttestations -d="${SCENARIOS}"/operations/attestation/pyspec_tests/success_multi_proposer_index_iterations/
+
+# Deposit processing
+build/nbench cmdBlockProcessing --blockProcessingCat=catDeposits -d="${SCENARIOS}"/operations/deposit/pyspec_tests/new_deposit_max/
+
+# Voluntary exit
+build/nbench cmdBlockProcessing --blockProcessingCat=catVoluntaryExits -d="${SCENARIOS}"/operations/voluntary_exit/pyspec_tests/validator_exit_in_future/
+```
+
+## Running the whole test suite
+
+Warning: this is a proof-of-concept, there is a slight degree of interleaving in output.
+Furthermore benchmarks are run in parallel and might interfere which each other.
+
+```
+nim c -d:const_preset=mainnet -d:nbench -d:release -o:build/nbench nbench/nbench.nim
+nim c -o:build/nbench_tests nbench/nbench_official_fixtures.nim
+nbench_tests --nbench=build/nbench --tests=tests/official/fixtures/tests-v0.9.3/mainnet/
+```
+
+## TODO Reporting
+- Dumping as CSV files also for archival, perf regression suite and/or data mining.
+- Piggybacking on eth-metrics and can report over Prometheus or StatsD.
+- you can augment it via label pragmas that can be applied file-wide
+  to tag "cryptography", "block_transition", "database" to have a global view
+  of the system.