Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[PH -> main] Performance Harness MVP [PH] #350

Merged
merged 319 commits into from
Dec 9, 2022

Conversation

oschwaldp-oci
Copy link
Contributor

@oschwaldp-oci oschwaldp-oci commented Oct 19, 2022

Performance Harness

The Performance Harness is configured and run through the main performance_test.py script. The script's main goal is to measure current peak performance metrics through iteratively tuning and running basic performance tests. The current basic test works to determine the maximum throughput of Token Transfers the system can sustain. It does this by conducting a binary search of possible Token Transfers Per Second (TPS) configurations, testing each configuration in a short duration test and scoring its result. The search algorithm iteratively configures and runs performance_test_basic.py tests and analyzes the output to determine a success metric used to continue the search. When the search completes, a max TPS throughput value is reported (along with other performance metrics from that run). The script then proceeds to conduct an additional search with longer duration test runs within a narrowed TPS configuration range to determine the sustainable max TPS. Finally it produces a report on the entire performance run, summarizing each individual test scenario, results, and full report details on the tests when maximum TPS was achieved (Performance Test Report)

The performance_test_basic.py support script performs a single basic performance test that targets a configurable TPS target and, if successful, reports statistics on performance metrics measured during the test. It configures and launches a blockchain test environment, creates wallets and accounts for testing, and configures and launches transaction generators for creating specific transaction load in the ecosystem. Finally it analyzes the performance of the system under the configuration through log analysis and chain queries and produces a Performance Test Basic Report.

The launch_generators.py support script provides a means to easily calculate and spawn the number of transaction generator instances to generate a given target TPS, distributing generation load between the instances in a fair manner such that the aggregate load meets the requested test load.

The log_reader.py support script is used primarily to analyze nodeos log files to glean information about generated blocks and transactions within those blocks after a test has concluded. This information is used to produce the performance test report. In similar fashion, read_log_data.py allows for recreating a report from the configuration and log files without needing to rerun the test.

ENF_Performance_Harness_MVP_Arch_11082022

Prerequisites

Please refer to Leap: Build and Install from Source for a full list of prerequisites.

New dependency - python NumPy, a package for scientific computing with Python.

If running on Ubuntu 18.04 an additional dependency will need to be installed to support modern python dataclasses:
python3 -m pip install dataclasses

Steps

  1. Build Leap. For complete instructions on building from source please refer to Leap: Build and Install from Source
  2. Run Performance Tests
    1. Full Performance Harness Test Run (Standard):
      ./build/tests/performance_tests/performance_test.py
    2. Single Performance Test Basic Run (Manually run one-off test):
      ./build/tests/performance_tests/performance_test_basic.py
  3. Collect Results - By default the Performance Harness will capture and save logs. To delete logs, use --del-perf-logs. Additionally, final reports will be collected by default. To omit final reports, use --del-report and/or --del-test-report.
    1. Navigate to performance test logs directory

      cd ./build/performance_test/
    2. Log Directory Structure is hierarchical with each run of the performance_test.py reporting into a timestamped directory where it includes the full performance report as well as a directory containing output from each test type run (here, performance_test_basic.py) and each individual test run outputs into a timestamped directory that may contain block data logs and transaction generator logs as well as the test's basic report. An example directory structure follows:

      Expand Example Directory Structure
      performance_test/
      └── 2022-10-27_15-28-09
          ├── report.json
          └── testRunLogs
              └── performance_test_basic
                  └── 2022-10-19_10-29-07
                      ├── blockDataLogs
                      │   ├── blockData.txt
                      │   └── blockTrxData.txt
                      ├── data.json
                      ├── etc
                      │   └── eosio
                      │       ├── launcher
                      │       │   └── testnet.template
                      │       ├── node_00
                      │       │   ├── config.ini
                      │       │   ├── genesis.json
                      │       │   ├── logging.json
                      │       │   └── protocol_features
                      │       │       ├── BUILTIN-ACTION_RETURN_VALUE.json
                      │       │       ├── BUILTIN-BLOCKCHAIN_PARAMETERS.json
                      │       │       ├── BUILTIN-CONFIGURABLE_WASM_LIMITS2.json
                      │       │       ├── BUILTIN-CRYPTO_PRIMITIVES.json
                      │       │       ├── BUILTIN-DISALLOW_EMPTY_PRODUCER_SCHEDULE.json
                      │       │       ├── BUILTIN-FIX_LINKAUTH_RESTRICTION.json
                      │       │       ├── BUILTIN-FORWARD_SETCODE.json
                      │       │       ├── BUILTIN-GET_BLOCK_NUM.json
                      │       │       ├── BUILTIN-GET_CODE_HASH.json
                      │       │       ├── BUILTIN-GET_SENDER.json
                      │       │       ├── BUILTIN-NO_DUPLICATE_DEFERRED_ID.json
                      │       │       ├── BUILTIN-ONLY_BILL_FIRST_AUTHORIZER.json
                      │       │       ├── BUILTIN-ONLY_LINK_TO_EXISTING_PERMISSION.json
                      │       │       ├── BUILTIN-PREACTIVATE_FEATURE.json
                      │       │       ├── BUILTIN-RAM_RESTRICTIONS.json
                      │       │       ├── BUILTIN-REPLACE_DEFERRED.json
                      │       │       ├── BUILTIN-RESTRICT_ACTION_TO_SELF.json
                      │       │       ├── BUILTIN-WEBAUTHN_KEY.json
                      │       │       └── BUILTIN-WTMSIG_BLOCK_SIGNATURES.json
                      │       ├── node_01
                      │       │   ├── config.ini
                      │       │   ├── genesis.json
                      │       │   ├── logging.json
                      │       │   └── protocol_features
                      │       │       ├── BUILTIN-ACTION_RETURN_VALUE.json
                      │       │       ├── BUILTIN-BLOCKCHAIN_PARAMETERS.json
                      │       │       ├── BUILTIN-CONFIGURABLE_WASM_LIMITS2.json
                      │       │       ├── BUILTIN-CRYPTO_PRIMITIVES.json
                      │       │       ├── BUILTIN-DISALLOW_EMPTY_PRODUCER_SCHEDULE.json
                      │       │       ├── BUILTIN-FIX_LINKAUTH_RESTRICTION.json
                      │       │       ├── BUILTIN-FORWARD_SETCODE.json
                      │       │       ├── BUILTIN-GET_BLOCK_NUM.json
                      │       │       ├── BUILTIN-GET_CODE_HASH.json
                      │       │       ├── BUILTIN-GET_SENDER.json
                      │       │       ├── BUILTIN-NO_DUPLICATE_DEFERRED_ID.json
                      │       │       ├── BUILTIN-ONLY_BILL_FIRST_AUTHORIZER.json
                      │       │       ├── BUILTIN-ONLY_LINK_TO_EXISTING_PERMISSION.json
                      │       │       ├── BUILTIN-PREACTIVATE_FEATURE.json
                      │       │       ├── BUILTIN-RAM_RESTRICTIONS.json
                      │       │       ├── BUILTIN-REPLACE_DEFERRED.json
                      │       │       ├── BUILTIN-RESTRICT_ACTION_TO_SELF.json
                      │       │       ├── BUILTIN-WEBAUTHN_KEY.json
                      │       │       └── BUILTIN-WTMSIG_BLOCK_SIGNATURES.json
                      │       └── node_bios
                      │           ├── config.ini
                      │           ├── genesis.json
                      │           ├── logging.json
                      │           └── protocol_features
                      │               ├── BUILTIN-ACTION_RETURN_VALUE.json
                      │               ├── BUILTIN-BLOCKCHAIN_PARAMETERS.json
                      │               ├── BUILTIN-CONFIGURABLE_WASM_LIMITS2.json
                      │               ├── BUILTIN-CRYPTO_PRIMITIVES.json
                      │               ├── BUILTIN-DISALLOW_EMPTY_PRODUCER_SCHEDULE.json
                      │               ├── BUILTIN-FIX_LINKAUTH_RESTRICTION.json
                      │               ├── BUILTIN-FORWARD_SETCODE.json
                      │               ├── BUILTIN-GET_BLOCK_NUM.json
                      │               ├── BUILTIN-GET_CODE_HASH.json
                      │               ├── BUILTIN-GET_SENDER.json
                      │               ├── BUILTIN-NO_DUPLICATE_DEFERRED_ID.json
                      │               ├── BUILTIN-ONLY_BILL_FIRST_AUTHORIZER.json
                      │               ├── BUILTIN-ONLY_LINK_TO_EXISTING_PERMISSION.json
                      │               ├── BUILTIN-PREACTIVATE_FEATURE.json
                      │               ├── BUILTIN-RAM_RESTRICTIONS.json
                      │               ├── BUILTIN-REPLACE_DEFERRED.json
                      │               ├── BUILTIN-RESTRICT_ACTION_TO_SELF.json
                      │               ├── BUILTIN-WEBAUTHN_KEY.json
                      │               └── BUILTIN-WTMSIG_BLOCK_SIGNATURES.json
                      ├── trxGenLogs
                      │   ├── trx_data_output_26451.txt
                      │   ├── trx_data_output_26452.txt
                      │   ├── trx_data_output_26453.txt
                      │   └── trx_data_output_26454.txt
                      └── var
                          └── var
                              ├── lib
                              │   ├── node_00
                              │   │   ├── blocks
                              │   │   │   ├── blocks.index
                              │   │   │   ├── blocks.log
                              │   │   │   └── reversible
                              │   │   ├── nodeos.pid
                              │   │   ├── snapshots
                              │   │   ├── state
                              │   │   │   └── shared_memory.bin
                              │   │   ├── stderr.2022_10_27_10_49_01.txt
                              │   │   ├── stderr.txt -> stderr.2022_10_27_10_49_01.txt
                              │   │   └── stdout.txt
                              │   ├── node_01
                              │   │   ├── blocks
                              │   │   │   ├── blocks.index
                              │   │   │   ├── blocks.log
                              │   │   │   └── reversible
                              │   │   ├── nodeos.pid
                              │   │   ├── snapshots
                              │   │   ├── state
                              │   │   │   └── shared_memory.bin
                              │   │   ├── stderr.2022_10_27_10_49_01.txt
                              │   │   ├── stderr.txt -> stderr.2022_10_27_10_49_01.txt
                              │   │   ├── stdout.txt
                              │   │   └── traces
                              │   │       ├── trace_0000000000-0000010000.log
                              │   │       ├── trace_index_0000000000-0000010000.log
                              │   │       └── trace_trx_id_0000000000-0000010000.log
                              │   └── node_bios
                              │       ├── blocks
                              │       │   ├── blocks.index
                              │       │   ├── blocks.log
                              │       │   └── reversible
                              │       │       └── fork_db.dat
                              │       ├── nodeos.pid
                              │       ├── snapshots
                              │       ├── state
                              │       │   └── shared_memory.bin
                              │       ├── stderr.2022_10_27_10_49_01.txt
                              │       ├── stderr.txt -> stderr.2022_10_27_10_49_01.txt
                              │       ├── stdout.txt
                              │       └── traces
                              │           ├── trace_0000000000-0000010000.log
                              │           ├── trace_index_0000000000-0000010000.log
                              │           └── trace_trx_id_0000000000-0000010000.log
                              ├── test_keosd_err.log
                              ├── test_keosd_out.log
                              └── test_wallet_0
                                  ├── config.ini
                                  ├── default.wallet
                                  ├── ignition.wallet
                                  ├── keosd.sock
                                  └── wallet.lock

Configuring Performance Harness Tests

Performance Test

The Performance Harness main script performance_test.py can be configured using the following command line arguments:

Expand Argument List
  • -p P producing nodes count (default: 1)
  • -n N total nodes (default: 0)
  • -d D delay between nodes startup (default: 1)
  • --nodes-file NODES_FILE
    File containing nodes info in JSON format. (default: None)
  • -s {mesh} topology (default: mesh)
  • --dump-error-details Upon error print etc/eosio/node_*/config.ini and var/lib/node_*/stderr.log to stdout (default: False)
  • -v verbose logging (default: False)
  • --leave-running Leave cluster running after test finishes (default: False)
  • --clean-run Kill all nodeos and keosd instances (default: False)
  • --max-tps-to-test MAX_TPS_TO_TEST
    The max target transfers realistic as ceiling of test range (default: 50000)
  • --test-iteration-duration-sec TEST_ITERATION_DURATION_SEC
    The duration of transfer trx generation for each iteration of the test during the initial search (seconds) (default: 30)
  • --test-iteration-min-step TEST_ITERATION_MIN_STEP
    The step size determining granularity of tps result during initial search (default: 500)
  • --final-iterations-duration-sec FINAL_ITERATIONS_DURATION_SEC
    The duration of transfer trx generation for each final longer run iteration of the test during
    the final search (seconds) (default: 90)
  • --tps-limit-per-generator TPS_LIMIT_PER_GENERATOR
    Maximum amount of transactions per second a single generator can have. (default: 4000)
  • --genesis GENESIS Path to genesis.json (default: tests/performance_tests/genesis.json)
  • --num-blocks-to-prune NUM_BLOCKS_TO_PRUNE
    The number of potentially non-empty blocks, in addition to leading and trailing size 0 blocks,
    to prune from the beginning and end of the range of blocks of interest for evaluation.
    (default: 2)
  • --signature-cpu-billable-pct SIGNATURE_CPU_BILLABLE_PCT
    Percentage of actual signature recovery cpu to bill. Whole number percentages, e.g. 50 for 50% (default: 0)
  • --chain-state-db-size-mb CHAIN_STATE_DB_SIZE_MB
    Maximum size (in MiB) of the chain state database (default: 10240)
  • --disable-subjective-billing DISABLE_SUBJECTIVE_BILLING
    Disable subjective CPU billing for API/P2P transactions (default: True)
  • --last-block-time-offset-us LAST_BLOCK_TIME_OFFSET_US
    Offset of last block producing time in microseconds. Valid range 0 .. -block_time_interval. (default: 0)
  • --produce-time-offset-us PRODUCE_TIME_OFFSET_US
    Offset of non last block producing time in microseconds. Valid range 0 .. -block_time_interval. (default: 0)
  • --cpu-effort-percent CPU_EFFORT_PERCENT
    Percentage of cpu block production time used to produce block. Whole number percentages, e.g. 80 for 80% (default: 100)
  • --last-block-cpu-effort-percent LAST_BLOCK_CPU_EFFORT_PERCENT
    Percentage of cpu block production time used to produce last block. Whole number percentages, e.g. 80 for 80% (default: 100)
  • --http-max-response-time-ms HTTP_MAX_RESPONSE_TIME_MS
    Maximum time for processing a request, -1 for unlimited (default: 990000)
  • --del-perf-logs Whether to delete performance test specific logs. (default: False)
  • --del-report Whether to delete overarching performance run report. (default: False)
  • --del-test-report Whether to save json reports from each test scenario. (default: False)
  • --quiet Whether to quiet printing intermediate results and reports to stdout (default: False)
  • --prods-enable-trace-api
    Determines whether producer nodes should have eosio::trace_api_plugin enabled (default: False)

Support Scripts

The following scripts are typically used by the Performance Harness main script performance_test.py to perform specific tasks as delegated and configured by the main script. However, there may be applications in certain use cases where running a single one-off test or transaction generator is desired. In those situations, the following argument details might be useful to understanding how to run these utilities in stand-alone mode. The argument breakdown may also be useful in understanding how the Performance Harness main script's arguments are being passed through to configure lower-level entities.

Performance Test Basic

performance_test_basic.py can be configured using the following command line arguments:

Expand Argument List
  • -p P producing nodes count (default: 1)
  • -n N total nodes (default: 0)
  • -d D delay between nodes startup (default: 1)
  • --nodes-file NODES_FILE
    File containing nodes info in JSON format. (default: None)
  • -s {mesh} topology (default: mesh)
  • --dump-error-details Upon error print etc/eosio/node_*/config.ini and var/lib/node_*/stderr.log to stdout (default: False)
  • -v verbose logging (default: False)
  • --leave-running Leave cluster running after test finishes (default: False)
  • --clean-run Kill all nodeos and keosd instances (default: False)
  • --target-tps TARGET_TPS
    The target transfers per second to send during test (default: 8000)
  • --tps-limit-per-generator TPS_LIMIT_PER_GENERATOR
    Maximum amount of transactions per second a single generator can have. (default: 4000)
  • --test-duration-sec TEST_DURATION_SEC
    The duration of transfer trx generation for the test in seconds (default: 30)
  • --genesis GENESIS Path to genesis.json (default: tests/performance_tests/genesis.json)
  • --num-blocks-to-prune NUM_BLOCKS_TO_PRUNE
    The number of potentially non-empty blocks, in addition to leading and trailing size 0 blocks, to prune from the beginning and end
    of the range of blocks of interest for evaluation. (default: 2)
  • --signature-cpu-billable-pct SIGNATURE_CPU_BILLABLE_PCT
    Percentage of actual signature recovery cpu to bill. Whole number percentages, e.g. 50 for 50% (default: 0)
  • --chain-state-db-size-mb CHAIN_STATE_DB_SIZE_MB
    Maximum size (in MiB) of the chain state database (default: 10240)
  • --disable-subjective-billing DISABLE_SUBJECTIVE_BILLING
    Disable subjective CPU billing for API/P2P transactions (default: True)
  • --last-block-time-offset-us LAST_BLOCK_TIME_OFFSET_US
    Offset of last block producing time in microseconds. Valid range 0 .. -block_time_interval. (default: 0)
  • --produce-time-offset-us PRODUCE_TIME_OFFSET_US
    Offset of non last block producing time in microseconds. Valid range 0 .. -block_time_interval. (default: 0)
  • --cpu-effort-percent CPU_EFFORT_PERCENT
    Percentage of cpu block production time used to produce block. Whole number percentages, e.g. 80 for 80% (default: 100)
  • --last-block-cpu-effort-percent LAST_BLOCK_CPU_EFFORT_PERCENT
    Percentage of cpu block production time used to produce last block. Whole number percentages, e.g. 80 for 80% (default: 100)
  • --http-max-response-time-ms HTTP_MAX_RESPONSE_TIME_MS
    Maximum time for processing a request, -1 for unlimited (default: 990000)
  • --del-perf-logs Whether to delete performance test specific logs. (default: False)
  • --del-report Whether to delete overarching performance run report. (default: False)
  • --quiet Whether to quiet printing intermediate results and reports to stdout (default: False)
  • --prods-enable-trace-api
    Determines whether producer nodes should have eosio::trace_api_plugin enabled (default: False)

Launch Transaction Generators

launch_transaction_generators.py can be configured using the following command line arguments:

Expand Argument List
  • chain_id set the chain id
  • last_irreversible_block_id Current last-irreversible-block-id (LIB ID) to use for transactions.
  • handler_account Account name of the handler account for the transfer actions
  • accounts Comma separated list of account names
  • priv_keys Comma separated list of private keys.
  • trx_gen_duration Transaction generation duration (seconds). Defaults to 60 seconds.
  • target_tps Target transactions per second to generate/send.
  • tps_limit_per_generator Maximum amount of transactions per second a single generator can have.
  • log_dir set the logs directory

Transaction Generator

The Transaction Generator is a program built to create and send transactions at a specified rate in order to generate load on a blockchain. It is comprised of 3 main components: Transaction Generator, Transaction Provider, and Performance Monitor.

The trx_generator.[hpp, cpp] is currently specialized to be a transfer_trx_generator primarily focused on generating token transfer transactions. The transactions are then provided to the network by the trx_provider.[hpp, cpp] which is currently aimed at the P2P network protocol in the p2p_trx_provider. The third component, the tps_performance_monitor, allows the Transaction Generator to monitor its own performance and take action to notify and exit if it is unable to keep up with the requested transaction generation rate.

The Transaction Generator logs each transaction's id and sent timestamp at the moment the Transaction Provider sends the transaction. Logs are written to the configured log directory and will follow the naming convention trx_data_output_10744.txt where 10744 is the transaction generator instance's process ID.

Configuration Options

./build/tests/trx_generator/trx_generator can be configured using the following command line arguments:

Expand Argument List
  • --chain-id arg set the chain id
  • --handler-account arg Account name of the handler account for
    the transfer actions
  • --accounts arg comma-separated list of accounts that
    will be used for transfers. Minimum
    required accounts: 2.
  • --priv-keys arg comma-separated list of private keys in
    same order of accounts list that will
    be used to sign transactions. Minimum
    required: 2.
  • --trx-expiration arg (=3600) transaction expiration time in seconds.
    Defaults to 3,600. Maximum allowed:
    3,600
  • --trx-gen-duration arg (=60) Transaction generation duration
    (seconds). Defaults to 60 seconds.
  • --target-tps arg (=1) Target transactions per second to
    generate/send. Defaults to 1
    transaction per second.
  • --last-irreversible-block-id arg Current last-irreversible-block-id (LIB
    ID) to use for transactions.
  • --monitor-spinup-time-us arg (=1000000)
    Number of microseconds to wait before
    monitoring TPS. Defaults to 1000000
    (1s).
  • --monitor-max-lag-percent arg (=5) Max percentage off from expected
    transactions sent before being in
    violation. Defaults to 5.
  • --monitor-max-lag-duration-us arg (=1000000)
    Max microseconds that transaction
    generation can be in violation before
    quitting. Defaults to 1000000 (1s).
  • --log-dir arg set the logs directory

Result Reports

Performance Test Report

The Performance Harness generates a report to summarize results of test scenarios as well as overarching results of the performance harness run. By default the report described below will be written to the top level timestamped directory for the performance run with the file name report.json. To omit final report, use --del-report.

Command used to run test and generate report:

.build/tests/performance_tests/performance_test.py --test-iteration-duration-sec 10 --final-iterations-duration-sec 30

Report Breakdown

The report begins by delivering the max TPS results of the performance run.

  • InitialMaxTpsAchieved - the max TPS throughput achieved during initial, short duration test scenarios to narrow search window
  • LongRunningMaxTpsAchieved - the max TPS throughput achieved during final, longer duration test scenarios to zero in on sustainable max TPS

Next, a summary of the search scenario conducted and respective results is included. Each summary includes information on the current state of the overarching search as well as basic results of the individual test that are used to determine whether the basic test was considered successful. The list of summary results are included in InitialSearchResults and LongRunningSearchResults. The number of entries in each list will vary depending on the TPS range tested (--max-tps-to-test) and the configured --test-iteration-min-step.

Expand Search Scenario Summary Example
    "0": {
      "success": false,
      "searchTarget": 25000,
      "searchFloor": 0,
      "searchCeiling": 50000,
      "basicTestResult": {
        "targetTPS": 25000,
        "resultAvgTps": 17160.4,
        "expectedTxns": 250000,
        "resultTxns": 250000,
        "tpsExpectMet": false,
        "trxExpectMet": true,
        "basicTestSuccess": true,
        "testAnalysisBlockCnt": 26,
        "logsDir": "performance_test/2022-10-26_15-01-51/testRunLogs/performance_test_basic/2022-10-26_15-01-51",
        "testStart": "2022-10-26T15:03:37.764242",
        "testEnd": "2022-10-26T15:01:51.128328"
      }
    }

Finally, the full detail test report for each of the determined max TPS throughput (InitialMaxTpsAchieved and LongRunningMaxTpsAchieved) runs is included after each scenario summary list in the full report. Note: In the example full report below, these have been truncated as they are single performance test basic run reports as detailed in the following section Performance Test Basic Report. Herein these truncated reports appear as:

Expand Truncated Report Example
"InitialMaxTpsReport": {
    <truncated>
    "Analysis": {
      <truncated>
    },
    "args": {
      <truncated>
    },
    "env": {
      <truncated>
    },
    <truncated>
}
Expand for full sample Performance Test Report
{
  "InitialMaxTpsAchieved": 16000,
  "LongRunningMaxTpsAchieved": 15000,
  "testStart": "2022-11-04T19:31:40.539240",
  "testFinish": "2022-11-04T19:48:53.096915",
  "InitialSearchResults": {
    "0": {
      "success": false,
      "searchTarget": 50000,
      "searchFloor": 0,
      "searchCeiling": 50000,
      "basicTestResult": {
        "targetTPS": 50000,
        "resultAvgTps": 15312.09090909091,
        "expectedTxns": 500000,
        "resultTxns": 362075,
        "tpsExpectMet": false,
        "trxExpectMet": false,
        "basicTestSuccess": true,
        "testAnalysisBlockCnt": 45,
        "logsDir": "performance_test/2022-11-04_19-31-40/testRunLogs/performance_test_basic/2022-11-04_19-31-40",
        "testStart": "2022-11-04T19:31:40.539927",
        "testEnd": "2022-11-04T19:33:16.377065"
      }
    },
    "1": {
      "success": false,
      "searchTarget": 25000,
      "searchFloor": 0,
      "searchCeiling": 49500,
      "basicTestResult": {
        "targetTPS": 25000,
        "resultAvgTps": 15098.241379310344,
        "expectedTxns": 250000,
        "resultTxns": 250000,
        "tpsExpectMet": false,
        "trxExpectMet": true,
        "basicTestSuccess": true,
        "testAnalysisBlockCnt": 30,
        "logsDir": "performance_test/2022-11-04_19-31-40/testRunLogs/performance_test_basic/2022-11-04_19-33-16",
        "testStart": "2022-11-04T19:33:16.471198",
        "testEnd": "2022-11-04T19:34:45.441319"
      }
    },
    "2": {
      "success": true,
      "searchTarget": 12500,
      "searchFloor": 0,
      "searchCeiling": 24500,
      "basicTestResult": {
        "targetTPS": 12500,
        "resultAvgTps": 12500.0625,
        "expectedTxns": 125000,
        "resultTxns": 125000,
        "tpsExpectMet": true,
        "trxExpectMet": true,
        "basicTestSuccess": true,
        "testAnalysisBlockCnt": 17,
        "logsDir": "performance_test/2022-11-04_19-31-40/testRunLogs/performance_test_basic/2022-11-04_19-34-45",
        "testStart": "2022-11-04T19:34:45.507994",
        "testEnd": "2022-11-04T19:36:01.234060"
      }
    },
    "3": {
      "success": false,
      "searchTarget": 19000,
      "searchFloor": 13000,
      "searchCeiling": 24500,
      "basicTestResult": {
        "targetTPS": 19000,
        "resultAvgTps": 15454.0,
        "expectedTxns": 190000,
        "resultTxns": 190000,
        "tpsExpectMet": false,
        "trxExpectMet": true,
        "basicTestSuccess": true,
        "testAnalysisBlockCnt": 22,
        "logsDir": "performance_test/2022-11-04_19-31-40/testRunLogs/performance_test_basic/2022-11-04_19-36-01",
        "testStart": "2022-11-04T19:36:01.277926",
        "testEnd": "2022-11-04T19:37:23.028124"
      }
    },
    "4": {
      "success": true,
      "searchTarget": 16000,
      "searchFloor": 13000,
      "searchCeiling": 18500,
      "basicTestResult": {
        "targetTPS": 16000,
        "resultAvgTps": 15900.625,
        "expectedTxns": 160000,
        "resultTxns": 160000,
        "tpsExpectMet": true,
        "trxExpectMet": true,
        "basicTestSuccess": true,
        "testAnalysisBlockCnt": 17,
        "logsDir": "performance_test/2022-11-04_19-31-40/testRunLogs/performance_test_basic/2022-11-04_19-37-23",
        "testStart": "2022-11-04T19:37:23.085923",
        "testEnd": "2022-11-04T19:38:41.744418"
      }
    },
    "5": {
      "success": false,
      "searchTarget": 17500,
      "searchFloor": 16500,
      "searchCeiling": 18500,
      "basicTestResult": {
        "targetTPS": 17500,
        "resultAvgTps": 15271.526315789473,
        "expectedTxns": 175000,
        "resultTxns": 175000,
        "tpsExpectMet": false,
        "trxExpectMet": true,
        "basicTestSuccess": true,
        "testAnalysisBlockCnt": 20,
        "logsDir": "performance_test/2022-11-04_19-31-40/testRunLogs/performance_test_basic/2022-11-04_19-38-41",
        "testStart": "2022-11-04T19:38:41.796745",
        "testEnd": "2022-11-04T19:40:02.097920"
      }
    },
    "6": {
      "success": false,
      "searchTarget": 17000,
      "searchFloor": 16500,
      "searchCeiling": 17000,
      "basicTestResult": {
        "targetTPS": 17000,
        "resultAvgTps": 15876.176470588236,
        "expectedTxns": 170000,
        "resultTxns": 170000,
        "tpsExpectMet": false,
        "trxExpectMet": true,
        "basicTestSuccess": true,
        "testAnalysisBlockCnt": 18,
        "logsDir": "performance_test/2022-11-04_19-31-40/testRunLogs/performance_test_basic/2022-11-04_19-40-02",
        "testStart": "2022-11-04T19:40:02.150305",
        "testEnd": "2022-11-04T19:41:21.802272"
      }
    },
    "7": {
      "success": false,
      "searchTarget": 16500,
      "searchFloor": 16500,
      "searchCeiling": 16500,
      "basicTestResult": {
        "targetTPS": 16500,
        "resultAvgTps": 16096.823529411764,
        "expectedTxns": 165000,
        "resultTxns": 165000,
        "tpsExpectMet": false,
        "trxExpectMet": true,
        "basicTestSuccess": true,
        "testAnalysisBlockCnt": 18,
        "logsDir": "performance_test/2022-11-04_19-31-40/testRunLogs/performance_test_basic/2022-11-04_19-41-21",
        "testStart": "2022-11-04T19:41:21.851918",
        "testEnd": "2022-11-04T19:42:40.991794"
      }
    }
  },
  "InitialMaxTpsReport": {
    <truncated>
    "Analysis": {
      <truncated>
    },
    "args": {
      <truncated>
    },
    "env": {
      <truncated>
    },
    <truncated>
  },
  "LongRunningSearchResults": {
    "0": {
      "success": false,
      "searchTarget": 16000,
      "searchFloor": 0,
      "searchCeiling": 16000,
      "basicTestResult": {
        "targetTPS": 16000,
        "resultAvgTps": 14954.266666666666,
        "expectedTxns": 480000,
        "resultTxns": 480000,
        "tpsExpectMet": false,
        "trxExpectMet": true,
        "basicTestSuccess": true,
        "testAnalysisBlockCnt": 61,
        "logsDir": "performance_test/2022-11-04_19-31-40/testRunLogs/performance_test_basic/2022-11-04_19-42-41",
        "testStart": "2022-11-04T19:42:41.051468",
        "testEnd": "2022-11-04T19:44:47.365905"
      }
    },
    "1": {
      "success": false,
      "searchTarget": 15500,
      "searchFloor": 0,
      "searchCeiling": 16000,
      "basicTestResult": {
        "targetTPS": 15500,
        "resultAvgTps": 15001.827586206897,
        "expectedTxns": 465000,
        "resultTxns": 465000,
        "tpsExpectMet": false,
        "trxExpectMet": true,
        "basicTestSuccess": true,
        "testAnalysisBlockCnt": 59,
        "logsDir": "performance_test/2022-11-04_19-31-40/testRunLogs/performance_test_basic/2022-11-04_19-44-47",
        "testStart": "2022-11-04T19:44:47.472961",
        "testEnd": "2022-11-04T19:46:52.818564"
      }
    },
    "2": {
      "success": true,
      "searchTarget": 15000,
      "searchFloor": 0,
      "searchCeiling": 16000,
      "basicTestResult": {
        "targetTPS": 15000,
        "resultAvgTps": 15023.464285714286,
        "expectedTxns": 450000,
        "resultTxns": 450000,
        "tpsExpectMet": true,
        "trxExpectMet": true,
        "basicTestSuccess": true,
        "testAnalysisBlockCnt": 57,
        "logsDir": "performance_test/2022-11-04_19-31-40/testRunLogs/performance_test_basic/2022-11-04_19-46-52",
        "testStart": "2022-11-04T19:46:52.960531",
        "testEnd": "2022-11-04T19:48:52.989694"
      }
    }
  },
  "LongRunningMaxTpsReport": {
    <truncated>
    "Analysis": {
      <truncated>
    },
    "args": {
      <truncated>
    },
    "env": {
      <truncated>
    },
    <truncated>
  },
  "args": {
    "killAll": false,
    "dontKill": false,
    "keepLogs": true,
    "dumpErrorDetails": false,
    "delay": 1,
    "nodesFile": null,
    "verbose": false,
    "_killEosInstances": true,
    "_killWallet": true,
    "pnodes": 1,
    "totalNodes": 0,
    "topo": "mesh",
    "extraNodeosArgs": {
      "chainPluginArgs": {
        "signatureCpuBillablePct": 0
      },
      "producerPluginArgs": {
        "disableSubjectiveBilling": true,
        "lastBlockTimeOffsetUs": 0,
        "produceTimeOffsetUs": 0,
        "cpuEffortPercent": 100,
        "lastBlockCpuEffortPercent": 100
      },
      "httpPluginArgs": {
        "httpMaxResponseTimeMs": 990000
      }
    },
    "useBiosBootFile": false,
    "genesisPath": "tests/performance_tests/genesis.json",
    "maximumP2pPerHost": 5000,
    "maximumClients": 0,
    "loggingDict": {
      "bios": "off"
    },
    "prodsEnableTraceApi": false,
    "specificExtraNodeosArgs": {
      "1": "--plugin eosio::trace_api_plugin"
    },
    "_totalNodes": 2,
    "testDurationSec": 10,
    "finalDurationSec": 30,
    "logsDir": "performance_test/2022-11-04_19-31-40",
    "maxTpsToTest": 50000,
    "testIterationMinStep": 500,
    "tpsLimitPerGenerator": 4000,
    "delReport": false,
    "delTestReport": false,
    "numAddlBlocksToPrune": 2,
    "quiet": false,
    "delPerfLogs": false
  },
  "env": {
    "system": "Linux",
    "os": "posix",
    "release": "5.10.102.1-microsoft-standard-WSL2"
  },
  "nodeosVersion": "v4.0.0-dev"
}

Performance Test Basic Report

The Performance Test Basic generates, by default, a report that details results of the test, statistics around metrics of interest, as well as diagnostic information about the test run. If performance_test.py is run with --del-test-report, or performance_test_basic.py is run with --del-report, the report described below will not be written. Otherwise the report will be written to the timestamped directory within the performance_test_basic log directory for the test run with the file name data.json.

Expand for full sample report
{
  "completedRun": true,
  "testStart": "2022-11-04T19:46:52.960531",
  "testFinish": "2022-11-04T19:48:52.989694",
  "Analysis": {
    "BlockSize": {
      "min": 1389312,
      "max": 1575800,
      "avg": 1474814.3157894737,
      "sigma": 40921.65290309434,
      "emptyBlocks": 0,
      "numBlocks": 57
    },
    "BlocksGuide": {
      "firstBlockNum": 2,
      "lastBlockNum": 232,
      "totalBlocks": 231,
      "testStartBlockNum": 105,
      "testEndBlockNum": 199,
      "setupBlocksCnt": 103,
      "tearDownBlocksCnt": 33,
      "leadingEmptyBlocksCnt": 1,
      "trailingEmptyBlocksCnt": 33,
      "configAddlDropCnt": 2,
      "testAnalysisBlockCnt": 57
    },
    "TPS": {
      "min": 14532,
      "max": 15477,
      "avg": 15023.464285714286,
      "sigma": 178.66938384762454,
      "emptyBlocks": 0,
      "numBlocks": 57,
      "configTps": 15000,
      "configTestDuration": 30,
      "tpsPerGenerator": [
        3750,
        3750,
        3750,
        3750
      ],
      "generatorCount": 4
    },
    "TrxCPU": {
      "min": 7.0,
      "max": 2647.0,
      "avg": 23.146035555555557,
      "sigma": 11.415769514864671,
      "samples": 450000
    },
    "TrxLatency": {
      "min": 0.0009999275207519531,
      "max": 0.5539999008178711,
      "avg": 0.2614889088874393,
      "sigma": 0.1450651327531534,
      "samples": 450000
    },
    "TrxNet": {
      "min": 24.0,
      "max": 25.0,
      "avg": 24.555564444444446,
      "sigma": 0.49690300111146485,
      "samples": 450000
    }
  },
  "args": {
    "killAll": false,
    "dontKill": false,
    "keepLogs": true,
    "dumpErrorDetails": false,
    "delay": 1,
    "nodesFile": null,
    "verbose": false,
    "_killEosInstances": true,
    "_killWallet": true,
    "pnodes": 1,
    "totalNodes": 0,
    "topo": "mesh",
    "extraNodeosArgs": {
      "chainPluginArgs": {
        "signatureCpuBillablePct": 0
      },
      "producerPluginArgs": {
        "disableSubjectiveBilling": true,
        "lastBlockTimeOffsetUs": 0,
        "produceTimeOffsetUs": 0,
        "cpuEffortPercent": 100,
        "lastBlockCpuEffortPercent": 100
      },
      "httpPluginArgs": {
        "httpMaxResponseTimeMs": 990000
      }
    },
    "useBiosBootFile": false,
    "genesisPath": "tests/performance_tests/genesis.json",
    "maximumP2pPerHost": 5000,
    "maximumClients": 0,
    "loggingDict": {
      "bios": "off"
    },
    "prodsEnableTraceApi": false,
    "specificExtraNodeosArgs": {
      "1": "--plugin eosio::trace_api_plugin"
    },
    "_totalNodes": 2,
    "delPerfLogs": false,
    "delReport": false,
    "expectedTransactionsSent": 450000,
    "numAddlBlocksToPrune": 2,
    "quiet": false,
    "targetTps": 15000,
    "testTrxGenDurationSec": 30,
    "tpsLimitPerGenerator": 4000
  },
  "env": {
    "system": "Linux",
    "os": "posix",
    "release": "5.10.102.1-microsoft-standard-WSL2",
    "logical_cpu_count": 16
  },
  "nodeosVersion": "v4.0.0-dev"
}

Supported nodeos versions

The Performance Harness currently supports scraping/analyzing nodeos v 2.0.14 log format up to the current format (v3+).

ndcgundlach and others added 30 commits August 26, 2022 12:32
Added unit tests for the tps_tester
…a_structures

Capture data and create usable data structures storing data in performance_test_basic.py
…nfigurable_logging

Performance harness cluster configurable logging
Refactored the trx_generator main code
…ons from performance_test_basic. Fix a bug in the test regarding cease block
…package

Update to test harness python package
…scripts

Refactor and Separate Python Script for Performance Harness
appArgs.add(flag="--produce-time-offset-us", type=int, help="Offset of non last block producing time in microseconds. Valid range 0 .. -block_time_interval.", default=0)
appArgs.add(flag="--cpu-effort-percent", type=int, help="Percentage of cpu block production time used to produce block. Whole number percentages, e.g. 80 for 80%%", default=100)
appArgs.add(flag="--last-block-cpu-effort-percent", type=int, help="Percentage of cpu block production time used to produce last block. Whole number percentages, e.g. 80 for 80%%", default=100)
appArgs.add(flag="--http-max-response-time-ms", type=int, help="Maximum time for processing a request, -1 for unlimited", default=990000)
Copy link
Member

Choose a reason for hiding this comment

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

Is there any alternative to replicating many of nodeos configuration options in a second location like this? (newer PRs have even more than the ~10 in this PR). Seems like a sneaky maintenance overhead, and especially prone to breakage for options not used by default.

A simple naive way to do this is to have a way to "forward" arguments to nodeos without the python code caring, For example instead of

perf.py --target-tps --test-duration-sec 60 --genesis ~/genesis.json --signature-cpu-billable-pct 50 --chain-state-db-size-mb 40

it becomes

perf.py --target-tps --test-duration-sec 60 -- --genesis ~/genesis.json --signature-cpu-billable-pct 50 --chain-state-db-size-mb 40

that is, everything after -- is simply forwarded along to nodeos.

Unfortunately that won't work here due to the defaults for these options in this performance test not being the same as the defaults of nodeos.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Is there any alternative to replicating many of nodeos configuration options in a second location like this? (newer PRs have even more than the ~10 in this PR). Seems like a sneaky maintenance overhead, and especially prone to breakage for options not used by default.

Some thoughts here:

There are several alternatives that are being discussed down at the Regression Test Framework (TestHarness) level, where TestHelper.py, Node.py and Cluster.py boostrap the blockchain test environment. The Performance Harness MVP was not intending to implement those during this effort, but will look to take advantage of them and integrate with them when they occur.

Currently in Cluster.py there is a catch-all argument extraNodeosArgs that functions similarly to your suggestion to pass on any command line provided extra arguments, not explicitly supported by a command line argument, directly to nodeos. However, in the Performance Harness there is a desire to have finer grain manipulation of configurations between specific nodes to measure specific configurations. We are trying to identify which arguments have performance impacts, and provide support directly for those. We are also providing defaults for most config options to either mirror those in nodeos itself or those that have been tuned for performance due to empirical analysis.

As far as maintainability is concerned, there is a basic test being run in CI/CD, which should catch if any config items change at the nodeos level that need to bubble up into the regression test and performance frameworks, since all config parameters used by the performance test (even those defaulted) are being passed to nodeos, and would cause a test failure if no longer matching nodeos options.

An effort was just completed to group configuration options such that they would not have to be reproduced at each level of script in the Performance Harness. The use of ArgumentParser parents and groups will help bubble component arguments up/down for reuse as well as provide groups for easier understanding of when to use each. That work is currently sitting in a PR for Stage 2 development here: #518.

Care was taken to make it easy to expand the supported set of nodeos configuration options. Adding a new command line option to nodeos is as simple as adding the argument in the ArgumentParser and in the plugin args object (PerformanceBasicTest.ClusterConfig.ExtraNodeosArgs.*PluginArgs).

The payload object can be extremely long when printing out during verbose logging.  Rarely is the entire response needed for debugging.  However, the code is often useful when something goes wrong.  Reverse the order of code and payload so that, when trunctating printed responsed, the return code is always available.  Truncate the response to 1024 characters.
[PH] Update response order and truncate when printing.
@spoonincode
Copy link
Member

The current runners really aren't designed for running a reliable (consistent) performance test. I was already concerned with this change extending test time some some minute and half, but it seems like you're going to have to keep dialing down the test until it's reliable too. And even then it may have side effects on other tests (which have been somewhat sensitive already). I'm not sure at what point we move performance testing to proper consistent performance runners.

@oschwaldp-oci
Copy link
Contributor Author

The current runners really aren't designed for running a reliable (consistent) performance test. I was already concerned with this change extending test time some some minute and half, but it seems like you're going to have to keep dialing down the test until it's reliable too. And even then it may have side effects on other tests (which have been somewhat sensitive already). I'm not sure at what point we move performance testing to proper consistent performance runners.

We are currently only running one test, the performance_test_basic.py as a smoke test since the Performance Harness is built on top of it. We were hoping to get it sized to where it should be able to run on these less performant runners and still see that the base test is still functioning as expected. It isn't really to see any performance numbers. We have most recently run into issues of failing tests due to other new tests being added on main then incorporated into this branch. Like you said, the side effects on other tests any time a new test is introduced can be non-deterministic with the way these runners perform.

@spoonincode
Copy link
Member

Since it's just a smoke test, why not run it at something very low like 10 trx/sec or such?

Getting it to pass on the CI runners should not be the goal: this is bucketed in as a unit test -- it must run and pass for users. If someone compiles Leap on a slow Raspberry Pi the expectation is that the unit tests pass. If we feel this smoke test needs to be 1000+ trx/sec then we likely need a new bucket of tests (performance_tests or something) that are clearly documented as "might fail" due to host system performance.

@oschwaldp-oci
Copy link
Contributor Author

oschwaldp-oci commented Dec 5, 2022

Since it's just a smoke test, why not run it at something very low like 10 trx/sec or such?

Getting it to pass on the CI runners should not be the goal: this is bucketed in as a unit test -- it must run and pass for users. If someone compiles Leap on a slow Raspberry Pi the expectation is that the unit tests pass. If we feel this smoke test needs to be 1000+ trx/sec then we likely need a new bucket of tests (performance_tests or something) that are clearly documented as "might fail" due to host system performance.

That's a good point. I agree. I'll lower the test performance expectations so it shouldn't ever have a problem passing. I do want to keep it requiring 2 transaction generators, but I can have them both churning out small amounts of trxs. I'll push up changes for this.

@spoonincode -> Addressed here: be7640e

@spoonincode spoonincode dismissed their stale review December 7, 2022 15:38

removing block due to ongoing reviews

Copy link
Member

@tedcahalleos tedcahalleos left a comment

Choose a reason for hiding this comment

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

I approve this MVP PR after discussions with Kevin, Peter and the team on a larger call due to the fact that it is standalone code, will not affect EOS Mainnet, and has been successfully tested by Kevin multiple times. This code tests a Leap node on a standalone box that cannot affect any other systems.

Copy link

@bhazzard bhazzard left a comment

Choose a reason for hiding this comment

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

Approving based on Kevin's successful tests.

Copy link
Member

@stephenpdeos stephenpdeos left a comment

Choose a reason for hiding this comment

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

Approved based on today's discussion.

@oschwaldp-oci oschwaldp-oci merged commit f2afae6 into main Dec 9, 2022
@oschwaldp-oci oschwaldp-oci deleted the feature_performance_harness branch December 9, 2022 17:36
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
OCI Work exclusive to OCI team
Projects
None yet
Development

Successfully merging this pull request may close these issues.

9 participants