diff --git a/.github/workflows/ci-al4.yml b/.github/workflows/ci-al4.yml index 5cad8468177..8bf56b1bbdb 100644 --- a/.github/workflows/ci-al4.yml +++ b/.github/workflows/ci-al4.yml @@ -60,7 +60,7 @@ jobs: run: | set -ex cd build - ./tests.sh --timeout 360 --output-on-failure -L bucket_a -LE lts_compatibility + ./tests.sh --timeout 600 --output-on-failure -L bucket_a -LE lts_compatibility -j "$(../scripts/ci-test-jobs.sh)" shell: bash - name: "Upload logs for AL4 virtual A" @@ -132,7 +132,7 @@ jobs: rm -rf /github/home/.cache mkdir -p /github/home/.cache - ./tests.sh --timeout 360 --output-on-failure -L bucket_b + ./tests.sh --timeout 600 --output-on-failure -L bucket_b -j "$(../scripts/ci-test-jobs.sh)" shell: bash - name: "Upload logs for AL4 virtual B" @@ -193,7 +193,7 @@ jobs: rm -rf /github/home/.cache mkdir -p /github/home/.cache - ./tests.sh --timeout 360 --output-on-failure -L bucket_c + ./tests.sh --timeout 600 --output-on-failure -L bucket_c -j "$(../scripts/ci-test-jobs.sh)" shell: bash - name: "Upload logs for AL4 virtual C" diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index e0ff26ae876..8295a7c100f 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -23,7 +23,7 @@ env: jobs: vmss-virtual-a: - name: "VMSS Virtual A" # CI Checks, Clang Tidy, Python package tests, Doc build, Unit tests, e2e (bucket_a) + name: "VMSS Virtual A" # CI Checks, Clang Tidy, Python package tests, Doc build, Unit tests runs-on: [ self-hosted, @@ -95,12 +95,6 @@ jobs: cd build ./tests.sh --output-on-failure -L unit -j$(nproc --all) - - name: "Run e2e tests (bucket_a)" - run: | - set -ex - cd build - ./tests.sh --timeout 360 --output-on-failure -L bucket_a - - name: "Upload logs for virtual A" uses: actions/upload-artifact@043fb46d1a93c77aae656e7c1c64a875d1fc6a0a # v7.0.1 with: @@ -170,7 +164,7 @@ jobs: rm -rf /github/home/.cache mkdir -p /github/home/.cache - ./tests.sh --timeout 360 --output-on-failure -L bucket_b + ./tests.sh --timeout 600 --output-on-failure -L bucket_b -j "$(../scripts/ci-test-jobs.sh)" shell: bash - name: "Upload logs for virtual B" @@ -188,7 +182,7 @@ jobs: if: success() || failure() vmss-virtual-c: - name: "VMSS Virtual C" # End-to-end tests (bucket_c) + name: "VMSS Virtual C" # End-to-end tests (bucket_a, bucket_c, partitions) runs-on: [ self-hosted, @@ -232,15 +226,14 @@ jobs: rm -rf /github/home/.cache mkdir -p /github/home/.cache - ./tests.sh --timeout 360 --output-on-failure -L bucket_c + # `partitions` is labelled bucket_c but gated on the `partitions` + # configuration, so selecting that configuration runs it alongside the + # rest of the bucket instead of in a serial step of its own. + # bucket_a runs here too: it is small, and job A is paced by its + # clang-tidy build rather than by anything it can share. + ./tests.sh --timeout 600 --output-on-failure -C partitions -L "bucket_a|bucket_c" -j "$(../scripts/ci-test-jobs.sh)" shell: bash - - name: "Run partitions tests" - run: | - set -ex - cd build - ./tests.sh --timeout 360 --output-on-failure -L partitions -C partitions - - name: "Upload logs for virtual C" uses: actions/upload-artifact@043fb46d1a93c77aae656e7c1c64a875d1fc6a0a # v7.0.1 with: diff --git a/CMakeLists.txt b/CMakeLists.txt index 2a42fed04b9..7358df061bd 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -1096,6 +1096,7 @@ if(BUILD_TESTS) NAME recovery_test PYTHON_SCRIPT ${CMAKE_SOURCE_DIR}/tests/recovery.py BUCKET bucket_b + PROCESSORS 9 ADDITIONAL_ARGS ${ADDITIONAL_RECOVERY_ARGS} --constitution @@ -1106,6 +1107,7 @@ if(BUILD_TESTS) NAME recovery_stale_snapshot_join_test PYTHON_SCRIPT ${CMAKE_SOURCE_DIR}/tests/identity_recovery_snapshot.py BUCKET bucket_b + PROCESSORS 3 ADDITIONAL_ARGS --regex ^recovery_stale_snapshot_join$ ) @@ -1113,6 +1115,7 @@ if(BUILD_TESTS) NAME recovery_intermediate_snapshot_join_test PYTHON_SCRIPT ${CMAKE_SOURCE_DIR}/tests/identity_recovery_snapshot.py BUCKET bucket_b + PROCESSORS 3 ADDITIONAL_ARGS --regex ^recovery_intermediate_snapshot_join$ ) @@ -1120,6 +1123,7 @@ if(BUILD_TESTS) NAME recovery_snapshot_endorsements_test PYTHON_SCRIPT ${CMAKE_SOURCE_DIR}/tests/recovery_snapshot_endorsements.py BUCKET bucket_b + PROCESSORS 1 ) add_e2e_test( @@ -1185,6 +1189,7 @@ if(BUILD_TESTS) NAME js_batched_stress_test PYTHON_SCRIPT ${CMAKE_SOURCE_DIR}/tests/e2e_batched.py BUCKET bucket_c + PROCESSORS 1 ADDITIONAL_ARGS --js-app-bundle ${CMAKE_SOURCE_DIR}/src/apps/batched @@ -1197,6 +1202,10 @@ if(BUILD_TESTS) NAME modules_test PYTHON_SCRIPT ${CMAKE_SOURCE_DIR}/tests/js-modules/modules.py BUCKET bucket_c + PROCESSORS 2 + # Runs npm install/build in js/ccf-app and tests/npm-app, which are shared + # with auth and programmability_and_jwt. + RESOURCE_LOCK js_ccf_app_build ADDITIONAL_ARGS --package js_generic @@ -1211,6 +1220,10 @@ if(BUILD_TESTS) PYTHON_SCRIPT ${CMAKE_SOURCE_DIR}/tests/js-custom-authorization/custom_authorization.py BUCKET bucket_c + PROCESSORS 4 + # run_interpreter_reuse npm installs tests/js-interpreter-reuse, whose + # file: dependency rebuilds the shared js/ccf-app package. + RESOURCE_LOCK js_ccf_app_build ADDITIONAL_ARGS --package js_generic @@ -1237,6 +1250,7 @@ if(BUILD_TESTS) PYTHON_SCRIPT ${CMAKE_SOURCE_DIR}/tests/governance.py CONSTITUTION ${CONSTITUTION_ARGS} BUCKET bucket_c + PROCESSORS 10 DETECT_DEADLOCKS ADDITIONAL_ARGS --initial-operator-count @@ -1249,6 +1263,7 @@ if(BUILD_TESTS) NAME code_update_test PYTHON_SCRIPT ${CMAKE_SOURCE_DIR}/tests/code_update.py BUCKET bucket_c + PROCESSORS 9 ADDITIONAL_ARGS --js-app-bundle ${CMAKE_SOURCE_DIR}/samples/apps/logging/js @@ -1276,6 +1291,7 @@ if(BUILD_TESTS) NAME e2e_logging PYTHON_SCRIPT ${CMAKE_SOURCE_DIR}/tests/e2e_logging.py BUCKET bucket_c + PROCESSORS 9 DETECT_DEADLOCKS ADDITIONAL_ARGS --js-app-bundle ${CMAKE_SOURCE_DIR}/samples/apps/logging/js ) @@ -1300,6 +1316,10 @@ if(BUILD_TESTS) PYTHON_SCRIPT ${CMAKE_SOURCE_DIR}/tests/programmability.py LABEL snp BUCKET bucket_c + PROCESSORS 5 + # Calls npm_tests.build_npm_app, which builds the shared js/ccf-app and + # tests/npm-app trees. + RESOURCE_LOCK js_ccf_app_build ) # This test uses large requests (so too slow for SAN) @@ -1308,6 +1328,7 @@ if(BUILD_TESTS) NAME e2e_limits PYTHON_SCRIPT ${CMAKE_SOURCE_DIR}/tests/limits.py BUCKET bucket_c + PROCESSORS 3 ) endif() @@ -1315,6 +1336,7 @@ if(BUILD_TESTS) NAME e2e_redirects PYTHON_SCRIPT ${CMAKE_SOURCE_DIR}/tests/redirects.py BUCKET bucket_c + PROCESSORS 8 ADDITIONAL_ARGS --js-app-bundle ${CMAKE_SOURCE_DIR}/samples/apps/logging/js ) @@ -1322,16 +1344,24 @@ if(BUILD_TESTS) NAME e2e_logging_http2 PYTHON_SCRIPT ${CMAKE_SOURCE_DIR}/tests/e2e_logging.py BUCKET bucket_b + PROCESSORS 8 ADDITIONAL_ARGS --js-app-bundle ${CMAKE_SOURCE_DIR}/samples/apps/logging/js --http2 ) + # Runs under the `partitions` configuration but is also labelled bucket_c, so + # that CI can schedule it alongside the rest of bucket_c. It is long but light + # (it drives a single partitioned network at a time), and its iptables DROP + # rules match only its own nodes' ports, so it does not disturb co-scheduled + # tests. add_e2e_test( NAME partitions PYTHON_SCRIPT ${CMAKE_SOURCE_DIR}/tests/partitions_test.py LABEL partitions + BUCKET bucket_c + PROCESSORS 5 DETECT_DEADLOCKS CONFIGURATIONS partitions ) @@ -1346,12 +1376,14 @@ if(BUILD_TESTS) NAME tls_stress_test PYTHON_SCRIPT ${CMAKE_SOURCE_DIR}/tests/connections.py BUCKET bucket_c + PROCESSORS 2 ) add_e2e_test( NAME tls_groups_test PYTHON_SCRIPT ${CMAKE_SOURCE_DIR}/tests/tls_groups.py BUCKET bucket_a + PROCESSORS 1 ) if(CLIENT_PROTOCOLS_TEST) @@ -1367,6 +1399,7 @@ if(BUILD_TESTS) NAME schema_test PYTHON_SCRIPT ${CMAKE_SOURCE_DIR}/tests/schema.py BUCKET bucket_b + PROCESSORS 11 ADDITIONAL_ARGS --constitution ${CMAKE_SOURCE_DIR}/samples/constitutions/virtual/virtual_attestation_actions.js @@ -1399,6 +1432,7 @@ if(BUILD_TESTS) PYTHON_SCRIPT ${CMAKE_SOURCE_DIR}/tests/lts_compatibility.py LABEL e2e BUCKET bucket_a + PROCESSORS 4 ADDITIONAL_ARGS ${LTS_TEST_ARGS} --constitution @@ -1425,6 +1459,7 @@ if(BUILD_TESTS) NAME nodes_test PYTHON_SCRIPT ${CMAKE_SOURCE_DIR}/tests/nodes.py BUCKET bucket_b + PROCESSORS 16 ADDITIONAL_ARGS ${RECONFIG_TEST_ARGS} ${ROTATION_TEST_ARGS} ) diff --git a/cmake/common.cmake b/cmake/common.cmake index cc06bc3c0ed..094c94031c9 100644 --- a/cmake/common.cmake +++ b/cmake/common.cmake @@ -122,15 +122,37 @@ endfunction() # bucket_c) so that .github/workflows/ci.yml can select the per-runner test set # with `ctest -L bucket_X`. Every PR-CI e2e test must be in exactly one bucket; # scripts/test-buckets-checks.sh flags unbucketed tests in `no_bucket:`. +# +# PROCESSORS declares how much of a runner a test occupies, so that CI can run a +# bucket with `ctest -j` without overloading the machine. Most e2e tests use +# infra.runner.ConcurrentRunner to drive several CCF networks at once, and the +# cost of a test is dominated by how many node processes it keeps alive rather +# than by its duration. The unit here is therefore "concurrently live CCF +# nodes", measured as the sum of node process lifetimes divided by the test's +# wall-clock duration. ctest keeps the sum of PROCESSORS across running tests +# within its `-j` budget, so these values decide what gets packed together. +# +# Re-measure with scripts/e2e-test-load.py against the node logs uploaded by a +# CI run when a test's set of sub-tests changes materially. +# +# RESOURCE_LOCK names a shared resource outside the test's own workspace, such +# as a directory it builds in. ctest never runs two tests holding the same lock +# concurrently. Tests that only touch their own CCF networks need no lock. function(add_e2e_test) cmake_parse_arguments( PARSE_ARGV 0 PARSED_ARGS "DETECT_DEADLOCKS" - "NAME;PYTHON_SCRIPT;LABEL;CURL_CLIENT;BUCKET" + "NAME;PYTHON_SCRIPT;LABEL;CURL_CLIENT;BUCKET;PROCESSORS;RESOURCE_LOCK" "CONSTITUTION;ADDITIONAL_ARGS;CONFIGURATIONS" ) + # Conservative default for tests that have not been measured. Only tests run + # with `ctest -j` (the CI buckets) are affected by this. + if(NOT PARSED_ARGS_PROCESSORS) + set(PARSED_ARGS_PROCESSORS 4) + endif() + if(NOT PARSED_ARGS_CONSTITUTION) set(PARSED_ARGS_CONSTITUTION ${CCF_NETWORK_TEST_DEFAULT_CONSTITUTION}) endif() @@ -213,6 +235,18 @@ function(add_e2e_test) PROPERTY LABELS ${PARSED_ARGS_LABEL} ) + set_property( + TEST ${PARSED_ARGS_NAME} + PROPERTY PROCESSORS ${PARSED_ARGS_PROCESSORS} + ) + + if(PARSED_ARGS_RESOURCE_LOCK) + set_property( + TEST ${PARSED_ARGS_NAME} + PROPERTY RESOURCE_LOCK ${PARSED_ARGS_RESOURCE_LOCK} + ) + endif() + if(PARSED_ARGS_BUCKET) set_property( TEST ${PARSED_ARGS_NAME} diff --git a/cmake/gersemi_definitions.cmake b/cmake/gersemi_definitions.cmake index c49905f095a..5d609e04d4e 100644 --- a/cmake/gersemi_definitions.cmake +++ b/cmake/gersemi_definitions.cmake @@ -24,7 +24,7 @@ function(add_e2e_test) PARSE_ARGV 0 PARSED_ARGS "DETECT_DEADLOCKS" - "NAME;PYTHON_SCRIPT;LABEL;CURL_CLIENT;BUCKET" + "NAME;PYTHON_SCRIPT;LABEL;CURL_CLIENT;BUCKET;PROCESSORS;RESOURCE_LOCK" "CONSTITUTION;ADDITIONAL_ARGS;CONFIGURATIONS" ) endfunction() diff --git a/scripts/ci-test-jobs.sh b/scripts/ci-test-jobs.sh new file mode 100755 index 00000000000..8a96cd24c7a --- /dev/null +++ b/scripts/ci-test-jobs.sh @@ -0,0 +1,38 @@ +#!/bin/bash +# Copyright (c) Microsoft Corporation. All rights reserved. +# Licensed under the Apache 2.0 License. + +# Prints the ctest `-j` budget to use for CCF's end-to-end test buckets. +# +# Each e2e test declares a PROCESSORS weight (see add_e2e_test in +# cmake/common.cmake) in units of concurrently live CCF node processes, and +# ctest keeps the sum of those weights within this budget. CCF nodes in e2e +# tests spend most of their time waiting on timers, sockets and disk rather +# than burning CPU, so the budget is deliberately larger than the core count. +# +# The multiplier is the safety knob: raising it packs more tests together and +# shortens the bucket, but starving nodes of CPU shows up as spurious +# leadership elections and flaky tests. Lower it if that happens. +# +# Override with CCF_CI_TEST_JOBS to pin an exact value. + +set -euo pipefail + +if [ -n "${CCF_CI_TEST_JOBS:-}" ]; then + echo "$CCF_CI_TEST_JOBS" + exit 0 +fi + +NODES_PER_CORE_NUMERATOR=3 +NODES_PER_CORE_DENOMINATOR=2 + +cores=$(nproc --all) +jobs=$((cores * NODES_PER_CORE_NUMERATOR / NODES_PER_CORE_DENOMINATOR)) + +# Never drop below the heaviest single test's weight, so that a test is never +# left unable to be scheduled alongside anything else on a small machine. +if [ "$jobs" -lt 16 ]; then + jobs=16 +fi + +echo "$jobs" diff --git a/scripts/e2e-test-load.py b/scripts/e2e-test-load.py new file mode 100755 index 00000000000..abe160fa57e --- /dev/null +++ b/scripts/e2e-test-load.py @@ -0,0 +1,154 @@ +#!/usr/bin/env python3 +# Copyright (c) Microsoft Corporation. All rights reserved. +# Licensed under the Apache 2.0 License. + +"""Measure the runner load of CCF end-to-end tests from CI logs. + +Each e2e test declares a ``PROCESSORS`` weight in ``CMakeLists.txt`` (see +``add_e2e_test`` in ``cmake/common.cmake``). The weight is expressed in +concurrently live CCF node processes, and ctest keeps the sum of the weights of +running tests within its ``-j`` budget. This script recomputes those weights +from a CI run so they can be refreshed when a test's set of sub-tests changes. + +Usage:: + + gh run download -n logs-azurelinux-virtual-b -D logs-b + gh run view --log > run.log + python scripts/e2e-test-load.py logs-b run.log + +``logs-b`` is the uploaded ``build/workspace`` tree: one directory per CCF node, +each containing the node's ``out``/``err`` logs. ``run.log`` is any file +containing the ctest summary lines, which give each test's wall-clock duration. + +A node's lifetime is the span between its first and last timestamped log line. +Summing node lifetimes for a test and dividing by the test's duration gives the +average number of nodes it keeps alive, which is what the weight should be. +""" + +import argparse +import math +import os +import re +import sys +from datetime import datetime + +LOG_TIMESTAMP = re.compile(r"^(\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d+)Z") + +# e.g. " 7/13 Test #84: e2e_logging ........... Passed 84.01 sec" +CTEST_RESULT = re.compile( + r"Test\s+#\d+:\s+(?P\S+)\s+\.+\s+\S+\s+(?P\d+\.\d+)\s+sec" +) + + +def parse_ctest_durations(path): + """Map ctest test name to its wall-clock duration in seconds.""" + durations = {} + with open(path, "r", errors="ignore") as f: + for line in f: + m = CTEST_RESULT.search(line) + if m: + # A test can appear in several jobs; keep the longest run, which + # is the one the weight has to accommodate. + name = m.group("name") + seconds = float(m.group("seconds")) + durations[name] = max(durations.get(name, 0.0), seconds) + return durations + + +def node_lifetime(node_dir): + """Seconds between a node's first and last timestamped log line.""" + first = last = None + for filename in ("out", "err"): + path = os.path.join(node_dir, filename) + if not os.path.isfile(path): + continue + with open(path, "r", errors="ignore") as f: + for line in f: + m = LOG_TIMESTAMP.match(line) + if not m: + continue + stamp = datetime.strptime(m.group(1)[:26], "%Y-%m-%dT%H:%M:%S.%f") + if first is None or stamp < first: + first = stamp + if last is None or stamp > last: + last = stamp + if first is None or last is None: + return 0.0 + return (last - first).total_seconds() + + +def owning_test(workspace_name, test_names): + """Attribute a workspace directory to the ctest test that created it. + + Workspace directories are named ``__``, where + the label is the ctest test name. Prefer the longest match so that, for + example, ``e2e_logging`` does not claim ``e2e_logging_http2``'s directories. + """ + best = None + for name in test_names: + if name in workspace_name and (best is None or len(name) > len(best)): + best = name + return best + + +def main(): + parser = argparse.ArgumentParser(description=__doc__) + parser.add_argument("workspace", help="Downloaded build/workspace log tree") + parser.add_argument("ctest_log", help="File containing ctest summary lines") + parser.add_argument( + "--min-duration", + type=float, + default=1.0, + help="Ignore tests shorter than this many seconds (default: 1.0)", + ) + args = parser.parse_args() + + durations = parse_ctest_durations(args.ctest_log) + if not durations: + print(f"No ctest result lines found in {args.ctest_log}", file=sys.stderr) + return 1 + + node_seconds = {name: 0.0 for name in durations} + node_counts = {name: 0 for name in durations} + leaked = [] + + for entry in sorted(os.listdir(args.workspace)): + node_dir = os.path.join(args.workspace, entry) + if not os.path.isdir(node_dir): + continue + name = owning_test(entry, durations) + if name is None: + continue + lifetime = node_lifetime(node_dir) + if lifetime <= 0: + continue + node_seconds[name] += lifetime + node_counts[name] += 1 + # A node living far longer than its own test was never reaped, which + # both wastes CPU and inflates the measured weight. + if lifetime > durations[name] * 1.5: + leaked.append((entry, lifetime, name, durations[name])) + + print(f"{'test':<44} {'wall_s':>8} {'nodes':>6} {'node_s':>9} {'PROCESSORS':>11}") + total = 0.0 + for name, wall in sorted(durations.items(), key=lambda kv: -kv[1]): + if wall < args.min_duration and node_counts[name] == 0: + continue + weight = max(1, math.ceil(node_seconds[name] / wall)) if wall > 0 else 1 + print( + f"{name:<44} {wall:8.1f} {node_counts[name]:6d} " + f"{node_seconds[name]:9.1f} {weight:11d}" + ) + total += wall + print(f"\nserial total: {total:.1f}s") + + if leaked: + print("\nNodes outliving their test (weights above are overstated):") + for entry, lifetime, name, wall in leaked: + print(f" {entry}: lived {lifetime:.0f}s, {name} took {wall:.0f}s") + + return 0 + + +if __name__ == "__main__": + sys.exit(main())