log call concurrency of db and executor APIs
Description
In the case of a dead lock in the executor this gauge should show a constant 1.
Type of Change
- [x] New feature
Which Components or Systems Does This Change Impact?
- [x] Validator Node
- [x] Full Node (API, Indexer, etc.)
How Has This Been Tested?
building
⏱️ 5h 40m total CI duration on this PR
| Job | Cumulative Duration | Recent Runs |
|---|---|---|
| execution-performance / single-node-performance | 1h 8m | 🟩 🟥 🟩 🟩 |
| forge-framework-upgrade-test / forge | 1h 1m | 🟥 🟥 🟩 🟩 |
| forge-compat-test / forge | 51m | 🟩 🟩 🟩 |
| forge-e2e-test / forge | 40m | 🟩 🟩 🟩 |
| execution-performance / test-target-determinator | 17m | 🟩 🟩 🟩 🟩 |
| test-target-determinator | 15m | 🟩 🟩 ⬜ 🟩 |
| check | 13m | 🟩 🟩 ⬜ 🟩 |
| general-lints | 9m | 🟩 🟩 🟩 ⬜ 🟩 |
| rust-cargo-deny | 9m | 🟩 🟩 🟩 ⬜ 🟩 |
| rust-move-tests | 9m | 🟩 |
| rust-move-tests | 8m | 🟩 |
| rust-move-tests | 8m | 🟩 |
| check-dynamic-deps | 6m | 🟩 🟩 🟩 🟩 🟩 |
| rust-doc-tests | 5m | 🟩 |
| rust-doc-tests | 5m | 🟩 |
| rust-doc-tests | 4m | 🟩 |
| rust-move-tests | 4m | ⬜ |
| semgrep/ci | 2m | 🟩 🟩 🟩 🟩 🟩 |
| rust-doc-tests | 2m | ⬜ |
| rust-move-tests | 2m | ⬜ |
| file_change_determinator | 58s | 🟩 🟩 🟩 🟩 🟩 |
| file_change_determinator | 56s | 🟩 🟩 🟩 🟩 🟩 |
| file_change_determinator | 41s | 🟩 🟩 🟩 🟩 |
| permission-check | 16s | 🟩 🟩 🟩 🟩 🟩 |
| permission-check | 14s | 🟩 🟩 🟩 🟩 🟩 |
| permission-check | 13s | 🟩 🟩 🟩 🟩 🟩 |
| permission-check | 12s | 🟩 🟩 🟩 🟩 🟩 |
| determine-docker-build-metadata | 10s | 🟩 🟩 🟩 🟩 |
| permission-check | 8s | 🟩 🟩 🟩 🟩 |
| Backport PR | 6s | 🟥 |
| permission-check | 3s | 🟩 |
Forge is running suite compat on d1bf834728a0cf166d993f4728dfca54f3086fb0 ==> c847b5e00316d62e82220c1bd97cf3aff5d377f8
- Grafana dashboard (auto-refresh)
- Humio Logs
- Axiom Logs
- Validator CPU Profile
- Fullnode CPU Profile
- Test runner output
- Test run is land-blocking
Forge is running suite framework_upgrade on d1bf834728a0cf166d993f4728dfca54f3086fb0 ==> c847b5e00316d62e82220c1bd97cf3aff5d377f8
- Grafana dashboard (auto-refresh)
- Humio Logs
- Axiom Logs
- Validator CPU Profile
- Fullnode CPU Profile
- Test runner output
- Test run is land-blocking
Forge is running suite realistic_env_max_load on c847b5e00316d62e82220c1bd97cf3aff5d377f8
- Grafana dashboard (auto-refresh)
- Humio Logs
- Axiom Logs
- Validator CPU Profile
- Fullnode CPU Profile
- Test runner output
- Test run is land-blocking
:white_check_mark: Forge suite realistic_env_max_load success on c847b5e00316d62e82220c1bd97cf3aff5d377f8
two traffics test: inner traffic : committed: 13575.48 txn/s, latency: 2928.96 ms, (p50: 2700 ms, p90: 3100 ms, p99: 3900 ms), latency samples: 5161720
two traffics test : committed: 100.05 txn/s, latency: 2606.59 ms, (p50: 2500 ms, p90: 2900 ms, p99: 8400 ms), latency samples: 1880
Latency breakdown for phase 0: ["QsBatchToPos: max: 0.248, avg: 0.220", "QsPosToProposal: max: 0.264, avg: 0.229", "ConsensusProposalToOrdered: max: 0.321, avg: 0.296", "ConsensusOrderedToCommit: max: 0.511, avg: 0.481", "ConsensusProposalToCommit: max: 0.808, avg: 0.777"]
Max non-epoch-change gap was: 0 rounds at version 0 (avg 0.00) [limit 4], 0.81s no progress at version 2752304 (avg 0.20s) [limit 15].
Max epoch-change gap was: 0 rounds at version 0 (avg 0.00) [limit 4], 8.23s no progress at version 2752302 (avg 8.23s) [limit 15].
Test Ok
- Grafana dashboard
- Humio Logs
- Axiom Logs
- Validator CPU Profile
- Fullnode CPU Profile
- Test runner output
- Test run is land-blocking
:x: Forge suite framework_upgrade failure on d1bf834728a0cf166d993f4728dfca54f3086fb0 ==> c847b5e00316d62e82220c1bd97cf3aff5d377f8
Compatibility test results for d1bf834728a0cf166d993f4728dfca54f3086fb0 ==> c847b5e00316d62e82220c1bd97cf3aff5d377f8 (PR)
Upgrade the nodes to version: c847b5e00316d62e82220c1bd97cf3aff5d377f8
framework_upgrade::framework-upgrade::full-framework-upgrade : committed: 1083.67 txn/s, submitted: 1085.55 txn/s, failed submission: 1.88 txn/s, expired: 1.88 txn/s, latency: 3092.26 ms, (p50: 2400 ms, p90: 6300 ms, p99: 7500 ms), latency samples: 92220
framework_upgrade::framework-upgrade::full-framework-upgrade : committed: 902.63 txn/s, submitted: 905.28 txn/s, failed submission: 2.65 txn/s, expired: 2.65 txn/s, latency: 3880.93 ms, (p50: 2100 ms, p90: 10800 ms, p99: 15100 ms), latency samples: 68000
5. check swarm health
Compatibility test for d1bf834728a0cf166d993f4728dfca54f3086fb0 ==> c847b5e00316d62e82220c1bd97cf3aff5d377f8 passed
Upgrade the remaining nodes to version: c847b5e00316d62e82220c1bd97cf3aff5d377f8
framework_upgrade::framework-upgrade::full-framework-upgrade : committed: 46.47 txn/s, submitted: 73.62 txn/s, failed submission: 0.20 txn/s, expired: 27.15 txn/s, latency: 1336.85 ms, (p50: 1400 ms, p90: 2100 ms, p99: 2400 ms), latency samples: 14227
Test Failed: Waiting for nodes to catch up to target version and epoch (None, Some(39)) timed out after 20 seconds, current status: Ok([("validator-0", 179874, 38), ("validator-1", 179874, 38), ("validator-2", 178205, 38), ("validator-3", 179874, 38)])
Stack backtrace:
0: anyhow::error::<impl anyhow::Error>::msg
at /usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/anyhow-1.0.79/src/error.rs:83:36
1: aptos_forge::interface::swarm::wait_for_all_nodes_to_catchup_to_target_version_or_epoch::{{closure}}
at ./testsuite/forge/src/interface/swarm.rs:459:24
2: aptos_forge::interface::swarm::wait_for_all_nodes_to_catchup_to_epoch::{{closure}}
at ./testsuite/forge/src/interface/swarm.rs:392:6
3: aptos_forge::interface::swarm::SwarmExt::wait_for_all_nodes_to_change_epoch::{{closure}}
at ./testsuite/forge/src/interface/swarm.rs:285:92
4: <core::pin::Pin<P> as core::future::future::Future>::poll
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/core/src/future/future.rs:123:9
5: aptos_forge::interface::swarm::SwarmExt::fork_check::{{closure}}
at ./testsuite/forge/src/interface/swarm.rs:196:14
6: <core::pin::Pin<P> as core::future::future::Future>::poll
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/core/src/future/future.rs:123:9
7: <aptos_testcases::framework_upgrade::FrameworkUpgrade as aptos_forge::interface::network::NetworkTest>::run::{{closure}}
at ./testsuite/testcases/src/framework_upgrade.rs:216:63
8: <core::pin::Pin<P> as core::future::future::Future>::poll
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/core/src/future/future.rs:123:9
9: tokio::runtime::park::CachedParkThread::block_on::{{closure}}
at /usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/park.rs:282:63
10: tokio::runtime::coop::with_budget
at /usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/coop.rs:107:5
11: tokio::runtime::coop::budget
at /usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/coop.rs:73:5
12: tokio::runtime::park::CachedParkThread::block_on
at /usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/park.rs:282:31
13: tokio::runtime::context::blocking::BlockingRegionGuard::block_on
at /usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/context/blocking.rs:66:9
14: tokio::runtime::handle::Handle::block_on::{{closure}}
at /usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/handle.rs:310:22
15: tokio::runtime::context::runtime::enter_runtime
at /usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/context/runtime.rs:65:16
16: tokio::runtime::handle::Handle::block_on
at /usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/handle.rs:309:9
17: aptos_forge::runner::Forge<F>::run::{{closure}}
at ./testsuite/forge/src/runner.rs:611:49
18: aptos_forge::runner::run_test
at ./testsuite/forge/src/runner.rs:684:11
19: aptos_forge::runner::Forge<F>::run
at ./testsuite/forge/src/runner.rs:611:30
20: forge::run_forge
at ./testsuite/forge-cli/src/main.rs:453:11
21: forge::main
at ./testsuite/forge-cli/src/main.rs:379:21
22: core::ops::function::FnOnce::call_once
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/core/src/ops/function.rs:250:5
23: std::sys_common::backtrace::__rust_begin_short_backtrace
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/sys_common/backtrace.rs:155:18
24: std::rt::lang_start::{{closure}}
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/rt.rs:166:18
25: core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &F>::call_once
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/core/src/ops/function.rs:284:13
26: std::panicking::try::do_call
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panicking.rs:552:40
27: std::panicking::try
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panicking.rs:516:19
28: std::panic::catch_unwind
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panic.rs:146:14
29: std::rt::lang_start_internal::{{closure}}
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/rt.rs:148:48
30: std::panicking::try::do_call
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panicking.rs:552:40
31: std::panicking::try
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panicking.rs:516:19
32: std::panic::catch_unwind
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panic.rs:146:14
33: std::rt::lang_start_internal
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/rt.rs:148:20
34: main
35: __libc_start_main
36: _start
Trailing Log Lines:
31: std::panicking::try
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panicking.rs:516:19
32: std::panic::catch_unwind
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panic.rs:146:14
33: std::rt::lang_start_internal
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/rt.rs:148:20
34: main
35: __libc_start_main
36: _start
Swarm logs can be found here: See fgi output for more information.
{"level":"INFO","source":{"package":"aptos_forge","file":"testsuite/forge/src/backend/k8s/cluster_helper.rs:292"},"thread_name":"main","hostname":"forge-framework-upgrade-pr-14370-1724266144-d1bf834728a0cf166d9","timestamp":"2024-08-21T19:07:10.547126Z","message":"Deleting namespace forge-framework-upgrade-pr-14370: Some(NamespaceStatus { conditions: None, phase: Some(\"Terminating\") })"}
{"level":"INFO","source":{"package":"aptos_forge","file":"testsuite/forge/src/backend/k8s/cluster_helper.rs:400"},"thread_name":"main","hostname":"forge-framework-upgrade-pr-14370-1724266144-d1bf834728a0cf166d9","timestamp":"2024-08-21T19:07:10.547147Z","message":"aptos-node resources for Forge removed in namespace: forge-framework-upgrade-pr-14370"}
failures:
framework_upgrade::framework-upgrade
test result: FAILED. 0 passed; 1 failed; 0 filtered out
Failed to run tests:
Tests Failed
Error: Tests Failed
Stack backtrace:
0: anyhow::error::<impl anyhow::Error>::msg
at /usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/anyhow-1.0.79/src/error.rs:83:36
1: aptos_forge::runner::Forge<F>::run
at ./testsuite/forge/src/runner.rs:636:13
2: forge::run_forge
at ./testsuite/forge-cli/src/main.rs:453:11
3: forge::main
at ./testsuite/forge-cli/src/main.rs:379:21
4: core::ops::function::FnOnce::call_once
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/core/src/ops/function.rs:250:5
5: std::sys_common::backtrace::__rust_begin_short_backtrace
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/sys_common/backtrace.rs:155:18
6: std::rt::lang_start::{{closure}}
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/rt.rs:166:18
7: core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &F>::call_once
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/core/src/ops/function.rs:284:13
8: std::panicking::try::do_call
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panicking.rs:552:40
9: std::panicking::try
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panicking.rs:516:19
10: std::panic::catch_unwind
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panic.rs:146:14
11: std::rt::lang_start_internal::{{closure}}
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/rt.rs:148:48
12: std::panicking::try::do_call
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panicking.rs:552:40
13: std::panicking::try
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panicking.rs:516:19
14: std::panic::catch_unwind
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panic.rs:146:14
15: std::rt::lang_start_internal
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/rt.rs:148:20
16: main
17: __libc_start_main
18: _start
Debugging output:
NAME READY STATUS RESTARTS AGE
aptos-node-0-validator-0 1/1 Running 0 13m
aptos-node-1-validator-0 1/1 Running 0 13m
aptos-node-2-validator-0 1/1 Running 0 7m11s
aptos-node-3-validator-0 1/1 Running 0 6m26s
genesis-aptos-genesis-eforge245-wd7qz 0/1 Completed 0 17m
- Grafana dashboard
- Humio Logs
- Axiom Logs
- Validator CPU Profile
- Fullnode CPU Profile
- Test runner output
- Test run is land-blocking
:white_check_mark: Forge suite compat success on d1bf834728a0cf166d993f4728dfca54f3086fb0 ==> c847b5e00316d62e82220c1bd97cf3aff5d377f8
Compatibility test results for d1bf834728a0cf166d993f4728dfca54f3086fb0 ==> c847b5e00316d62e82220c1bd97cf3aff5d377f8 (PR)
1. Check liveness of validators at old version: d1bf834728a0cf166d993f4728dfca54f3086fb0
compatibility::simple-validator-upgrade::liveness-check : committed: 8645.37 txn/s, latency: 3899.97 ms, (p50: 2400 ms, p90: 11100 ms, p99: 28700 ms), latency samples: 348260
2. Upgrading first Validator to new version: c847b5e00316d62e82220c1bd97cf3aff5d377f8
compatibility::simple-validator-upgrade::single-validator-upgrading : committed: 7383.07 txn/s, latency: 3645.04 ms, (p50: 3900 ms, p90: 5000 ms, p99: 5100 ms), latency samples: 133980
compatibility::simple-validator-upgrade::single-validator-upgrade : committed: 7402.09 txn/s, latency: 4171.04 ms, (p50: 4000 ms, p90: 6900 ms, p99: 7300 ms), latency samples: 245780
3. Upgrading rest of first batch to new version: c847b5e00316d62e82220c1bd97cf3aff5d377f8
compatibility::simple-validator-upgrade::half-validator-upgrading : committed: 6987.94 txn/s, latency: 3901.00 ms, (p50: 4100 ms, p90: 5400 ms, p99: 5600 ms), latency samples: 145640
compatibility::simple-validator-upgrade::half-validator-upgrade : committed: 6980.25 txn/s, latency: 4480.83 ms, (p50: 4400 ms, p90: 7100 ms, p99: 7400 ms), latency samples: 238060
4. upgrading second batch to new version: c847b5e00316d62e82220c1bd97cf3aff5d377f8
compatibility::simple-validator-upgrade::rest-validator-upgrading : committed: 11679.15 txn/s, latency: 2279.50 ms, (p50: 2400 ms, p90: 2800 ms, p99: 3000 ms), latency samples: 208880
compatibility::simple-validator-upgrade::rest-validator-upgrade : committed: 10956.54 txn/s, latency: 2896.01 ms, (p50: 2800 ms, p90: 3800 ms, p99: 6400 ms), latency samples: 365080
5. check swarm health
Compatibility test for d1bf834728a0cf166d993f4728dfca54f3086fb0 ==> c847b5e00316d62e82220c1bd97cf3aff5d377f8 passed
Test Ok
- Grafana dashboard
- Humio Logs
- Axiom Logs
- Validator CPU Profile
- Fullnode CPU Profile
- Test runner output
- Test run is land-blocking
Forge is running suite framework_upgrade on d1bf834728a0cf166d993f4728dfca54f3086fb0 ==> c847b5e00316d62e82220c1bd97cf3aff5d377f8
- Grafana dashboard (auto-refresh)
- Humio Logs
- Axiom Logs
- Validator CPU Profile
- Fullnode CPU Profile
- Test runner output
- Test run is land-blocking
:x: Forge suite framework_upgrade failure on d1bf834728a0cf166d993f4728dfca54f3086fb0 ==> c847b5e00316d62e82220c1bd97cf3aff5d377f8
Compatibility test results for d1bf834728a0cf166d993f4728dfca54f3086fb0 ==> c847b5e00316d62e82220c1bd97cf3aff5d377f8 (PR)
Upgrade the nodes to version: c847b5e00316d62e82220c1bd97cf3aff5d377f8
framework_upgrade::framework-upgrade::full-framework-upgrade : committed: 199.54 txn/s, submitted: 230.82 txn/s, failed submission: 0.19 txn/s, expired: 31.28 txn/s, latency: 2103.10 ms, (p50: 2100 ms, p90: 3000 ms, p99: 3600 ms), latency samples: 63523
Test Failed: Waiting for nodes to catch up to target version and epoch (None, Some(9)) timed out after 20 seconds, current status: Ok([("validator-0", 64777, 8), ("validator-1", 63605, 8), ("validator-2", 64777, 8), ("validator-3", 64777, 8)])
Stack backtrace:
0: anyhow::error::<impl anyhow::Error>::msg
at /usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/anyhow-1.0.79/src/error.rs:83:36
1: aptos_forge::interface::swarm::wait_for_all_nodes_to_catchup_to_target_version_or_epoch::{{closure}}
at ./testsuite/forge/src/interface/swarm.rs:459:24
2: aptos_forge::interface::swarm::wait_for_all_nodes_to_catchup_to_epoch::{{closure}}
at ./testsuite/forge/src/interface/swarm.rs:392:6
3: aptos_forge::interface::swarm::SwarmExt::wait_for_all_nodes_to_change_epoch::{{closure}}
at ./testsuite/forge/src/interface/swarm.rs:285:92
4: <core::pin::Pin<P> as core::future::future::Future>::poll
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/core/src/future/future.rs:123:9
5: aptos_forge::interface::swarm::SwarmExt::fork_check::{{closure}}
at ./testsuite/forge/src/interface/swarm.rs:196:14
6: <core::pin::Pin<P> as core::future::future::Future>::poll
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/core/src/future/future.rs:123:9
7: <aptos_testcases::framework_upgrade::FrameworkUpgrade as aptos_forge::interface::network::NetworkTest>::run::{{closure}}
at ./testsuite/testcases/src/framework_upgrade.rs:93:63
8: <core::pin::Pin<P> as core::future::future::Future>::poll
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/core/src/future/future.rs:123:9
9: tokio::runtime::park::CachedParkThread::block_on::{{closure}}
at /usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/park.rs:282:63
10: tokio::runtime::coop::with_budget
at /usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/coop.rs:107:5
11: tokio::runtime::coop::budget
at /usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/coop.rs:73:5
12: tokio::runtime::park::CachedParkThread::block_on
at /usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/park.rs:282:31
13: tokio::runtime::context::blocking::BlockingRegionGuard::block_on
at /usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/context/blocking.rs:66:9
14: tokio::runtime::handle::Handle::block_on::{{closure}}
at /usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/handle.rs:310:22
15: tokio::runtime::context::runtime::enter_runtime
at /usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/context/runtime.rs:65:16
16: tokio::runtime::handle::Handle::block_on
at /usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.35.1/src/runtime/handle.rs:309:9
17: aptos_forge::runner::Forge<F>::run::{{closure}}
at ./testsuite/forge/src/runner.rs:611:49
18: aptos_forge::runner::run_test
at ./testsuite/forge/src/runner.rs:684:11
19: aptos_forge::runner::Forge<F>::run
at ./testsuite/forge/src/runner.rs:611:30
20: forge::run_forge
at ./testsuite/forge-cli/src/main.rs:453:11
21: forge::main
at ./testsuite/forge-cli/src/main.rs:379:21
22: core::ops::function::FnOnce::call_once
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/core/src/ops/function.rs:250:5
23: std::sys_common::backtrace::__rust_begin_short_backtrace
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/sys_common/backtrace.rs:155:18
24: std::rt::lang_start::{{closure}}
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/rt.rs:166:18
25: core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &F>::call_once
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/core/src/ops/function.rs:284:13
26: std::panicking::try::do_call
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panicking.rs:552:40
27: std::panicking::try
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panicking.rs:516:19
28: std::panic::catch_unwind
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panic.rs:146:14
29: std::rt::lang_start_internal::{{closure}}
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/rt.rs:148:48
30: std::panicking::try::do_call
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panicking.rs:552:40
31: std::panicking::try
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panicking.rs:516:19
32: std::panic::catch_unwind
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panic.rs:146:14
33: std::rt::lang_start_internal
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/rt.rs:148:20
34: main
35: __libc_start_main
36: _start
Trailing Log Lines:
31: std::panicking::try
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panicking.rs:516:19
32: std::panic::catch_unwind
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panic.rs:146:14
33: std::rt::lang_start_internal
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/rt.rs:148:20
34: main
35: __libc_start_main
36: _start
Swarm logs can be found here: See fgi output for more information.
{"level":"INFO","source":{"package":"aptos_forge","file":"testsuite/forge/src/backend/k8s/cluster_helper.rs:292"},"thread_name":"main","hostname":"forge-framework-upgrade-pr-14370-1724267970-d1bf834728a0cf166d9","timestamp":"2024-08-21T19:29:27.490227Z","message":"Deleting namespace forge-framework-upgrade-pr-14370: Some(NamespaceStatus { conditions: None, phase: Some(\"Terminating\") })"}
{"level":"INFO","source":{"package":"aptos_forge","file":"testsuite/forge/src/backend/k8s/cluster_helper.rs:400"},"thread_name":"main","hostname":"forge-framework-upgrade-pr-14370-1724267970-d1bf834728a0cf166d9","timestamp":"2024-08-21T19:29:27.490256Z","message":"aptos-node resources for Forge removed in namespace: forge-framework-upgrade-pr-14370"}
Failed to run tests:
Tests Failed
failures:
framework_upgrade::framework-upgrade
test result: FAILED. 0 passed; 1 failed; 0 filtered out
Error: Tests Failed
Stack backtrace:
0: anyhow::error::<impl anyhow::Error>::msg
at /usr/local/cargo/registry/src/index.crates.io-6f17d22bba15001f/anyhow-1.0.79/src/error.rs:83:36
1: aptos_forge::runner::Forge<F>::run
at ./testsuite/forge/src/runner.rs:636:13
2: forge::run_forge
at ./testsuite/forge-cli/src/main.rs:453:11
3: forge::main
at ./testsuite/forge-cli/src/main.rs:379:21
4: core::ops::function::FnOnce::call_once
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/core/src/ops/function.rs:250:5
5: std::sys_common::backtrace::__rust_begin_short_backtrace
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/sys_common/backtrace.rs:155:18
6: std::rt::lang_start::{{closure}}
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/rt.rs:166:18
7: core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &F>::call_once
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/core/src/ops/function.rs:284:13
8: std::panicking::try::do_call
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panicking.rs:552:40
9: std::panicking::try
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panicking.rs:516:19
10: std::panic::catch_unwind
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panic.rs:146:14
11: std::rt::lang_start_internal::{{closure}}
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/rt.rs:148:48
12: std::panicking::try::do_call
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panicking.rs:552:40
13: std::panicking::try
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panicking.rs:516:19
14: std::panic::catch_unwind
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/panic.rs:146:14
15: std::rt::lang_start_internal
at /rustc/9b00956e56009bab2aa15d7bff10916599e3d6d6/library/std/src/rt.rs:148:20
16: main
17: __libc_start_main
18: _start
Debugging output:
NAME READY STATUS RESTARTS AGE
aptos-node-0-validator-0 1/1 Running 0 7m15s
aptos-node-1-validator-0 1/1 Running 0 6m44s
aptos-node-2-validator-0 1/1 Running 0 9m45s
aptos-node-3-validator-0 1/1 Running 0 9m45s
genesis-aptos-genesis-eforge164-95ghj 0/1 Completed 0 9m56s
- Grafana dashboard
- Humio Logs
- Axiom Logs
- Validator CPU Profile
- Fullnode CPU Profile
- Test runner output
- Test run is land-blocking
Forge is running suite framework_upgrade on d1bf834728a0cf166d993f4728dfca54f3086fb0 ==> 0a0ef612cda4cbd2731c4205754357c5fd29a5d0
- Grafana dashboard (auto-refresh)
- Humio Logs
- Axiom Logs
- Validator CPU Profile
- Fullnode CPU Profile
- Test runner output
- Test run is land-blocking
Forge is running suite realistic_env_max_load on 0a0ef612cda4cbd2731c4205754357c5fd29a5d0
- Grafana dashboard (auto-refresh)
- Humio Logs
- Axiom Logs
- Validator CPU Profile
- Fullnode CPU Profile
- Test runner output
- Test run is land-blocking
Forge is running suite compat on d1bf834728a0cf166d993f4728dfca54f3086fb0 ==> 0a0ef612cda4cbd2731c4205754357c5fd29a5d0
- Grafana dashboard (auto-refresh)
- Humio Logs
- Axiom Logs
- Validator CPU Profile
- Fullnode CPU Profile
- Test runner output
- Test run is land-blocking
:white_check_mark: Forge suite realistic_env_max_load success on 0a0ef612cda4cbd2731c4205754357c5fd29a5d0
two traffics test: inner traffic : committed: 11930.02 txn/s, latency: 3332.47 ms, (p50: 3200 ms, p90: 3900 ms, p99: 6000 ms), latency samples: 4536060
two traffics test : committed: 99.98 txn/s, latency: 2641.89 ms, (p50: 2400 ms, p90: 3600 ms, p99: 5900 ms), latency samples: 1860
Latency breakdown for phase 0: ["QsBatchToPos: max: 0.247, avg: 0.229", "QsPosToProposal: max: 0.570, avg: 0.531", "ConsensusProposalToOrdered: max: 0.338, avg: 0.327", "ConsensusOrderedToCommit: max: 0.543, avg: 0.516", "ConsensusProposalToCommit: max: 0.868, avg: 0.843"]
Max non-epoch-change gap was: 0 rounds at version 0 (avg 0.00) [limit 4], 1.12s no progress at version 1935810 (avg 0.24s) [limit 15].
Max epoch-change gap was: 0 rounds at version 0 (avg 0.00) [limit 4], 7.25s no progress at version 1935808 (avg 7.25s) [limit 15].
Test Ok
- Grafana dashboard
- Humio Logs
- Axiom Logs
- Validator CPU Profile
- Fullnode CPU Profile
- Test runner output
- Test run is land-blocking
:white_check_mark: Forge suite framework_upgrade success on d1bf834728a0cf166d993f4728dfca54f3086fb0 ==> 0a0ef612cda4cbd2731c4205754357c5fd29a5d0
Compatibility test results for d1bf834728a0cf166d993f4728dfca54f3086fb0 ==> 0a0ef612cda4cbd2731c4205754357c5fd29a5d0 (PR)
Upgrade the nodes to version: 0a0ef612cda4cbd2731c4205754357c5fd29a5d0
framework_upgrade::framework-upgrade::full-framework-upgrade : committed: 1234.77 txn/s, submitted: 1237.77 txn/s, failed submission: 3.00 txn/s, expired: 3.00 txn/s, latency: 2515.43 ms, (p50: 2300 ms, p90: 3700 ms, p99: 5800 ms), latency samples: 107020
framework_upgrade::framework-upgrade::full-framework-upgrade : committed: 1111.09 txn/s, submitted: 1113.79 txn/s, failed submission: 2.70 txn/s, expired: 2.70 txn/s, latency: 2717.89 ms, (p50: 2400 ms, p90: 4600 ms, p99: 6800 ms), latency samples: 98780
5. check swarm health
Compatibility test for d1bf834728a0cf166d993f4728dfca54f3086fb0 ==> 0a0ef612cda4cbd2731c4205754357c5fd29a5d0 passed
Upgrade the remaining nodes to version: 0a0ef612cda4cbd2731c4205754357c5fd29a5d0
framework_upgrade::framework-upgrade::full-framework-upgrade : committed: 1160.94 txn/s, submitted: 1163.40 txn/s, failed submission: 2.46 txn/s, expired: 2.46 txn/s, latency: 2624.92 ms, (p50: 2400 ms, p90: 4200 ms, p99: 6000 ms), latency samples: 103840
Test Ok
- Grafana dashboard
- Humio Logs
- Axiom Logs
- Validator CPU Profile
- Fullnode CPU Profile
- Test runner output
- Test run is land-blocking
:white_check_mark: Forge suite compat success on d1bf834728a0cf166d993f4728dfca54f3086fb0 ==> 0a0ef612cda4cbd2731c4205754357c5fd29a5d0
Compatibility test results for d1bf834728a0cf166d993f4728dfca54f3086fb0 ==> 0a0ef612cda4cbd2731c4205754357c5fd29a5d0 (PR)
1. Check liveness of validators at old version: d1bf834728a0cf166d993f4728dfca54f3086fb0
compatibility::simple-validator-upgrade::liveness-check : committed: 12573.84 txn/s, latency: 2343.61 ms, (p50: 1800 ms, p90: 2400 ms, p99: 23800 ms), latency samples: 495580
2. Upgrading first Validator to new version: 0a0ef612cda4cbd2731c4205754357c5fd29a5d0
compatibility::simple-validator-upgrade::single-validator-upgrading : committed: 7187.55 txn/s, latency: 3945.01 ms, (p50: 4500 ms, p90: 4900 ms, p99: 5100 ms), latency samples: 131140
compatibility::simple-validator-upgrade::single-validator-upgrade : committed: 6077.14 txn/s, latency: 5029.75 ms, (p50: 5300 ms, p90: 5600 ms, p99: 6800 ms), latency samples: 230200
3. Upgrading rest of first batch to new version: 0a0ef612cda4cbd2731c4205754357c5fd29a5d0
compatibility::simple-validator-upgrade::half-validator-upgrading : committed: 7465.66 txn/s, latency: 3873.42 ms, (p50: 4200 ms, p90: 4800 ms, p99: 4800 ms), latency samples: 142300
compatibility::simple-validator-upgrade::half-validator-upgrade : committed: 6939.47 txn/s, latency: 4573.19 ms, (p50: 4500 ms, p90: 7000 ms, p99: 7500 ms), latency samples: 243120
4. upgrading second batch to new version: 0a0ef612cda4cbd2731c4205754357c5fd29a5d0
compatibility::simple-validator-upgrade::rest-validator-upgrading : committed: 12406.82 txn/s, latency: 2160.66 ms, (p50: 2300 ms, p90: 2600 ms, p99: 2700 ms), latency samples: 215500
compatibility::simple-validator-upgrade::rest-validator-upgrade : committed: 11482.71 txn/s, latency: 2678.58 ms, (p50: 2500 ms, p90: 4600 ms, p99: 5700 ms), latency samples: 376140
5. check swarm health
Compatibility test for d1bf834728a0cf166d993f4728dfca54f3086fb0 ==> 0a0ef612cda4cbd2731c4205754357c5fd29a5d0 passed
Test Ok
- Grafana dashboard
- Humio Logs
- Axiom Logs
- Validator CPU Profile
- Fullnode CPU Profile
- Test runner output
- Test run is land-blocking
Forge is running suite realistic_env_max_load on a93e75936631d57d9bd12f7d1b6d95c2d609c693
- Grafana dashboard (auto-refresh)
- Humio Logs
- Axiom Logs
- Validator CPU Profile
- Fullnode CPU Profile
- Test runner output
- Test run is land-blocking
Forge is running suite framework_upgrade on d1bf834728a0cf166d993f4728dfca54f3086fb0 ==> a93e75936631d57d9bd12f7d1b6d95c2d609c693
- Grafana dashboard (auto-refresh)
- Humio Logs
- Axiom Logs
- Validator CPU Profile
- Fullnode CPU Profile
- Test runner output
- Test run is land-blocking
Forge is running suite compat on d1bf834728a0cf166d993f4728dfca54f3086fb0 ==> a93e75936631d57d9bd12f7d1b6d95c2d609c693
- Grafana dashboard (auto-refresh)
- Humio Logs
- Axiom Logs
- Validator CPU Profile
- Fullnode CPU Profile
- Test runner output
- Test run is land-blocking
:white_check_mark: Forge suite compat success on d1bf834728a0cf166d993f4728dfca54f3086fb0 ==> a93e75936631d57d9bd12f7d1b6d95c2d609c693
Compatibility test results for d1bf834728a0cf166d993f4728dfca54f3086fb0 ==> a93e75936631d57d9bd12f7d1b6d95c2d609c693 (PR)
1. Check liveness of validators at old version: d1bf834728a0cf166d993f4728dfca54f3086fb0
compatibility::simple-validator-upgrade::liveness-check : committed: 10405.40 txn/s, latency: 3120.74 ms, (p50: 2100 ms, p90: 3300 ms, p99: 28200 ms), latency samples: 418640
2. Upgrading first Validator to new version: a93e75936631d57d9bd12f7d1b6d95c2d609c693
compatibility::simple-validator-upgrade::single-validator-upgrading : committed: 6461.56 txn/s, latency: 4248.14 ms, (p50: 4900 ms, p90: 5200 ms, p99: 5400 ms), latency samples: 123880
compatibility::simple-validator-upgrade::single-validator-upgrade : committed: 6218.40 txn/s, latency: 4891.27 ms, (p50: 4600 ms, p90: 7800 ms, p99: 8000 ms), latency samples: 214660
3. Upgrading rest of first batch to new version: a93e75936631d57d9bd12f7d1b6d95c2d609c693
compatibility::simple-validator-upgrade::half-validator-upgrading : committed: 6722.27 txn/s, latency: 3950.38 ms, (p50: 4300 ms, p90: 5400 ms, p99: 5700 ms), latency samples: 120320
compatibility::simple-validator-upgrade::half-validator-upgrade : committed: 6758.07 txn/s, latency: 4694.53 ms, (p50: 4800 ms, p90: 6900 ms, p99: 7100 ms), latency samples: 222780
4. upgrading second batch to new version: a93e75936631d57d9bd12f7d1b6d95c2d609c693
compatibility::simple-validator-upgrade::rest-validator-upgrading : committed: 11405.94 txn/s, latency: 2391.40 ms, (p50: 2600 ms, p90: 2900 ms, p99: 3000 ms), latency samples: 202920
compatibility::simple-validator-upgrade::rest-validator-upgrade : committed: 10702.45 txn/s, latency: 3021.80 ms, (p50: 2800 ms, p90: 4100 ms, p99: 7000 ms), latency samples: 352460
5. check swarm health
Compatibility test for d1bf834728a0cf166d993f4728dfca54f3086fb0 ==> a93e75936631d57d9bd12f7d1b6d95c2d609c693 passed
Test Ok
- Grafana dashboard
- Humio Logs
- Axiom Logs
- Validator CPU Profile
- Fullnode CPU Profile
- Test runner output
- Test run is land-blocking
:white_check_mark: Forge suite realistic_env_max_load success on a93e75936631d57d9bd12f7d1b6d95c2d609c693
two traffics test: inner traffic : committed: 12464.00 txn/s, latency: 3191.19 ms, (p50: 3000 ms, p90: 3600 ms, p99: 7200 ms), latency samples: 4739080
two traffics test : committed: 99.95 txn/s, latency: 2569.60 ms, (p50: 2500 ms, p90: 3100 ms, p99: 4300 ms), latency samples: 1780
Latency breakdown for phase 0: ["QsBatchToPos: max: 0.261, avg: 0.225", "QsPosToProposal: max: 0.396, avg: 0.360", "ConsensusProposalToOrdered: max: 0.332, avg: 0.318", "ConsensusOrderedToCommit: max: 0.704, avg: 0.646", "ConsensusProposalToCommit: max: 1.027, avg: 0.964"]
Max non-epoch-change gap was: 0 rounds at version 0 (avg 0.00) [limit 4], 0.83s no progress at version 2004058 (avg 0.22s) [limit 15].
Max epoch-change gap was: 0 rounds at version 0 (avg 0.00) [limit 4], 7.60s no progress at version 2004056 (avg 7.60s) [limit 15].
Test Ok
- Grafana dashboard
- Humio Logs
- Axiom Logs
- Validator CPU Profile
- Fullnode CPU Profile
- Test runner output
- Test run is land-blocking
:white_check_mark: Forge suite framework_upgrade success on d1bf834728a0cf166d993f4728dfca54f3086fb0 ==> a93e75936631d57d9bd12f7d1b6d95c2d609c693
Compatibility test results for d1bf834728a0cf166d993f4728dfca54f3086fb0 ==> a93e75936631d57d9bd12f7d1b6d95c2d609c693 (PR)
Upgrade the nodes to version: a93e75936631d57d9bd12f7d1b6d95c2d609c693
framework_upgrade::framework-upgrade::full-framework-upgrade : committed: 1143.61 txn/s, submitted: 1146.50 txn/s, failed submission: 2.89 txn/s, expired: 2.89 txn/s, latency: 2773.26 ms, (p50: 2400 ms, p90: 4700 ms, p99: 6000 ms), latency samples: 102860
framework_upgrade::framework-upgrade::full-framework-upgrade : committed: 1163.07 txn/s, submitted: 1164.23 txn/s, failed submission: 1.16 txn/s, expired: 1.16 txn/s, latency: 2694.84 ms, (p50: 2400 ms, p90: 4200 ms, p99: 6000 ms), latency samples: 99860
5. check swarm health
Compatibility test for d1bf834728a0cf166d993f4728dfca54f3086fb0 ==> a93e75936631d57d9bd12f7d1b6d95c2d609c693 passed
Upgrade the remaining nodes to version: a93e75936631d57d9bd12f7d1b6d95c2d609c693
framework_upgrade::framework-upgrade::full-framework-upgrade : committed: 1199.66 txn/s, submitted: 1201.45 txn/s, failed submission: 1.79 txn/s, expired: 1.79 txn/s, latency: 2593.12 ms, (p50: 2400 ms, p90: 4200 ms, p99: 5700 ms), latency samples: 107020
Test Ok
- Grafana dashboard
- Humio Logs
- Axiom Logs
- Validator CPU Profile
- Fullnode CPU Profile
- Test runner output
- Test run is land-blocking