Skip to content

Commit 50b3361

Browse files
Balance coverage shards on Linux test times (#1806)
* Print per-target test timings from CI shards ci-test-shard.py now echoes cargo's merged output and records each test binary's `finished in` time, then prints one `ci-test-shard: timings` JSON line at the end of the shard, with the build time up to the first test binary. The log tail is all the log API returns, so this is how a Linux coverage runtime sample can be read back: the only sample in the repo is from Windows, which models Linux coverage badly (#1768). Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_011f9aeQpFXjqvowuU1RFbdQ * Balance coverage shards on a Linux sample coverage (2) sets the merge-queue critical path: with the count split its test step ran 248 s against 173 s for shard 1 on this PR's first run, and 307-335 s against 176-179 s in recent merge_group runs. #1768 balanced on the Windows sample and saved nothing because Windows times don't model instrumented Linux targets (e2e_vendor_pypi_build: 35-72 s on Linux, 0 s in the Windows sample). ci-coverage-durations.json is this PR's own first coverage run, read back from the new timings line. unit_seconds adds ~34 s to the unit runtime for building the unit-test harnesses, and compile_seconds is 0.3 s, both fitted from the two shards' build and report times. Coverage uses it unless CI_TEST_TIMINGS is set. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_011f9aeQpFXjqvowuU1RFbdQ * Harden the shard runner and retune the sample Review fixes for the timings capture: forward cargo's output as raw bytes (Windows decoded UTF-8 as cp1252 and could raise on write), stop reading 10 s after cargo exits so a daemon a test left holding the pipe can't hang the shard, strip ANSI colour before matching, and return the first-binary time from run() instead of a sentinel key. The first balanced run overshot: shard 1's test step went 173 -> 229 s and shard 2's 248 -> 202 s. unit_seconds goes up by that 27 s gap. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_011f9aeQpFXjqvowuU1RFbdQ * Keep draining cargo's pipe after a write error If echoing to stdout failed (BrokenPipeError when tee dies), the reader thread exited and cargo blocked on a full pipe, so proc.wait() never returned and the shard sat until the job timeout. The reader now stops echoing but keeps reading and recording timings. Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_011f9aeQpFXjqvowuU1RFbdQ --------- Co-authored-by: Claude <noreply@anthropic.com>
1 parent e8de9cc commit 50b3361

3 files changed

Lines changed: 451 additions & 15 deletions

File tree

‎scripts/ci-coverage-durations.json‎

Lines changed: 246 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,246 @@
1+
{
2+
"source_run": 40801155956,
3+
"source_jobs": [
4+
123209371302,
5+
123209371281
6+
],
7+
"unit_seconds": 90.7,
8+
"compile_seconds": 0.3,
9+
"default_seconds": 1.0,
10+
"targets": {
11+
"api_retry_e2e": 0.12,
12+
"api_timeout_e2e": 4.04,
13+
"apply": 2.5,
14+
"binary_fetch_error_classification_e2e": 0.0,
15+
"blob_fetcher_edges_e2e": 0.06,
16+
"child_deadline_guard": 0.08,
17+
"cli": 4.7,
18+
"cli_apply_silent": 0.01,
19+
"cli_argv_non_utf8": 0.0,
20+
"cli_config_fallback": 0.09,
21+
"cli_get_silent": 0.01,
22+
"cli_global_args": 0.12,
23+
"cli_parse_apply": 0.0,
24+
"cli_parse_get": 0.02,
25+
"cli_parse_list": 0.04,
26+
"cli_parse_main": 0.03,
27+
"cli_parse_remove": 0.01,
28+
"cli_parse_repair": 0.01,
29+
"cli_parse_rollback": 0.0,
30+
"cli_parse_scan": 0.05,
31+
"cli_parse_vendor": 0.02,
32+
"cli_parse_vex": 0.01,
33+
"cli_path_flags_validated": 0.13,
34+
"cli_remove_silent": 0.03,
35+
"cli_scan_silent": 0.05,
36+
"cli_sigpipe": 0.01,
37+
"command_module_layering": 0.03,
38+
"contract_gradle_codes": 0.36,
39+
"contract_paid_required": 0.0,
40+
"crawl_fd_limit_e2e": 0.15,
41+
"crawler_cargo_e2e": 0.01,
42+
"crawler_composer_e2e": 0.27,
43+
"crawler_deno_e2e": 0.0,
44+
"crawler_go_e2e": 0.01,
45+
"crawler_gradle_e2e": 0.18,
46+
"crawler_maven_e2e": 0.01,
47+
"crawler_monorepo_gaps": 0.01,
48+
"crawler_npm_e2e": 7.78,
49+
"crawler_nuget_e2e": 0.04,
50+
"crawler_python_e2e": 0.34,
51+
"crawler_ruby_e2e": 0.28,
52+
"crawlers_empty_paths_e2e": 0.02,
53+
"docker_e2e_cargo": 0.0,
54+
"docker_e2e_composer": 0.0,
55+
"docker_e2e_deno": 0.0,
56+
"docker_e2e_gem": 0.0,
57+
"docker_e2e_golang": 0.0,
58+
"docker_e2e_maven": 0.0,
59+
"docker_e2e_npm": 0.0,
60+
"docker_e2e_nuget": 0.0,
61+
"docker_e2e_pypi": 0.0,
62+
"docker_e2e_sbt": 0.0,
63+
"docker_e2e_vendor_composer": 0.0,
64+
"docker_e2e_vendor_gem": 0.0,
65+
"docker_e2e_vendor_maven": 0.0,
66+
"docker_e2e_vendor_nuget": 0.0,
67+
"docker_e2e_vendor_pypi_pm": 0.0,
68+
"e2e_bun_lockb": 0.01,
69+
"e2e_cargo": 0.09,
70+
"e2e_composer": 0.03,
71+
"e2e_composer_vendor_dir_hints": 0.02,
72+
"e2e_composer_version_identity": 0.04,
73+
"e2e_embedded_vex": 0.04,
74+
"e2e_gem": 0.02,
75+
"e2e_golang": 0.02,
76+
"e2e_golang_build": 1.7,
77+
"e2e_golang_hosted_build": 3.26,
78+
"e2e_golang_hosted_state": 0.09,
79+
"e2e_golang_workspace_build": 3.12,
80+
"e2e_gradle_agent_build": 0.01,
81+
"e2e_gradle_discovery_build": 0.07,
82+
"e2e_hosted_production": 0.0,
83+
"e2e_maven": 0.02,
84+
"e2e_npm": 0.0,
85+
"e2e_nuget": 0.02,
86+
"e2e_nuget_dotnet_build": 0.0,
87+
"e2e_pypi": 0.0,
88+
"e2e_pypi_bytecode": 0.15,
89+
"e2e_pypi_multi_copy": 0.05,
90+
"e2e_redirect_bun_build": 0.01,
91+
"e2e_redirect_cargo_build": 0.66,
92+
"e2e_redirect_cargo_shapes": 2.85,
93+
"e2e_redirect_composer_build": 0.0,
94+
"e2e_redirect_gem_build": 0.0,
95+
"e2e_redirect_gem_stale_install": 0.71,
96+
"e2e_redirect_gradle_build": 0.02,
97+
"e2e_redirect_maven_build": 0.0,
98+
"e2e_redirect_npm_build": 0.0,
99+
"e2e_redirect_pnpm_build": 0.03,
100+
"e2e_redirect_rush_sim": 0.0,
101+
"e2e_redirect_uv_build": 0.0,
102+
"e2e_redirect_vlt_build": 0.0,
103+
"e2e_redirect_yarn_berry_build": 14.37,
104+
"e2e_redirect_yarn_classic_build": 6.44,
105+
"e2e_safety_cargo_build": 0.02,
106+
"e2e_safety_cow": 0.08,
107+
"e2e_safety_internals": 0.0,
108+
"e2e_safety_lock": 1.01,
109+
"e2e_safety_pnpm": 0.0,
110+
"e2e_safety_vlt": 0.01,
111+
"e2e_safety_yarn_pnp": 0.08,
112+
"e2e_sbt": 0.16,
113+
"e2e_sbt_build": 0.0,
114+
"e2e_sbt_hosted": 0.1,
115+
"e2e_sbt_vendor": 0.48,
116+
"e2e_sbt_vendor_build": 0.0,
117+
"e2e_scala_cli_vendor": 0.17,
118+
"e2e_scan": 0.0,
119+
"e2e_socket_yml_policy": 0.87,
120+
"e2e_vendor_bun_build": 0.02,
121+
"e2e_vendor_cargo_build": 0.74,
122+
"e2e_vendor_composer_build": 0.01,
123+
"e2e_vendor_composer_crlf": 0.05,
124+
"e2e_vendor_gem_build": 0.0,
125+
"e2e_vendor_golang_build": 1.03,
126+
"e2e_vendor_gradle_build": 0.02,
127+
"e2e_vendor_jvm_build": 0.03,
128+
"e2e_vendor_maven_build": 0.0,
129+
"e2e_vendor_npm_build": 1.24,
130+
"e2e_vendor_pnpm_build": 12.61,
131+
"e2e_vendor_pypi_build": 34.89,
132+
"e2e_vendor_vlt_build": 0.0,
133+
"e2e_vendor_yarn_berry_build": 2.22,
134+
"e2e_vendor_yarn_classic_build": 0.95,
135+
"e2e_vendor_yarn_classic_dev_flow": 1.81,
136+
"e2e_vendored_production": 0.0,
137+
"e2e_vex": 0.15,
138+
"e2e_vex_build": 0.0,
139+
"e2e_vex_lockfile": 11.21,
140+
"e2e_vex_redirect": 0.41,
141+
"e2e_vex_vendor": 0.14,
142+
"e2e_vlt": 0.56,
143+
"e2e_yarn4_pnpm_linker_build": 2.57,
144+
"e2e_yarn4_workspaces_build": 2.08,
145+
"e2e_yarn_legacy_cachekey_refusal_build": 0.71,
146+
"ecosystem_dispatch_e2e": 0.21,
147+
"fuzzy_match_e2e": 0.0,
148+
"get": 0.68,
149+
"global_probe_spawn_e2e": 0.02,
150+
"global_scope_project_state": 0.24,
151+
"gradle_agent_cli": 0.29,
152+
"help_text_hygiene": 0.11,
153+
"hosted_inventory": 0.06,
154+
"hosted_memory_engine": 0.78,
155+
"hosted_memory_parity": 0.26,
156+
"hosted_memory_rollout": 0.22,
157+
"hosted_superseding_pypi": 0.07,
158+
"in_process_agent_reapply": 0.14,
159+
"in_process_alternate_installers": 4.58,
160+
"in_process_cargo_apply": 0.82,
161+
"in_process_edge_cases": 0.17,
162+
"in_process_gem_apply": 0.55,
163+
"in_process_gem_multi_platform": 0.26,
164+
"in_process_get": 0.11,
165+
"in_process_get_corrupt_manifest": 0.0,
166+
"in_process_get_hosted_ecosystems": 0.29,
167+
"in_process_get_manifest_path": 0.06,
168+
"in_process_get_modes": 0.13,
169+
"in_process_get_update_count": 0.01,
170+
"in_process_get_uuid_fallback": 0.01,
171+
"in_process_pypi_apply": 8.43,
172+
"in_process_pypi_multi_release": 9.6,
173+
"in_process_python_envs": 0.22,
174+
"in_process_redirect": 4.06,
175+
"in_process_redirect_pdm": 0.47,
176+
"in_process_redirect_pipenv": 0.67,
177+
"in_process_redirect_pnpm": 1.81,
178+
"in_process_redirect_poetry": 0.27,
179+
"in_process_remote_ecosystems_apply": 1.04,
180+
"in_process_remove_repair_lifecycle": 0.56,
181+
"in_process_rollback_all_ecosystems": 0.57,
182+
"in_process_rollback_hosted": 1.96,
183+
"in_process_rollback_vendored": 0.19,
184+
"in_process_scan": 0.19,
185+
"in_process_scan_withdrawn": 0.35,
186+
"in_process_target_ambiguity": 0.51,
187+
"in_process_vendor": 5.58,
188+
"in_process_vendor_bun_takeover": 0.42,
189+
"in_process_vendor_npm_v1_takeover": 0.12,
190+
"in_process_vendor_pnpm_parent_child": 0.17,
191+
"in_process_vendor_pnpm_takeover": 0.19,
192+
"in_process_vendor_pypi_takeover": 0.1,
193+
"json_error_shape": 0.03,
194+
"manifest_load_error_matrix": 0.16,
195+
"manifest_path_ledger_root": 0.09,
196+
"maven_sidecar_cli": 0.05,
197+
"mode_migration_bun": 0.0,
198+
"mode_migration_cargo": 0.78,
199+
"mode_migration_composer": 0.31,
200+
"mode_migration_npm": 3.45,
201+
"mode_migration_pypi": 1.06,
202+
"mode_migration_vlt": 0.01,
203+
"output_helpers_e2e": 0.0,
204+
"package_e2e": 0.01,
205+
"pnpm_hosted": 0.02,
206+
"poetry_hosted": 0.02,
207+
"policy_pypi_names": 0.07,
208+
"proxy_batch_e2e": 0.42,
209+
"redirect_golden": 0.11,
210+
"redirect_sbt_golden": 0.09,
211+
"remedy_commands_parse": 0.17,
212+
"remove": 0.78,
213+
"remove_rollback_api_overrides": 0.01,
214+
"repair": 1.54,
215+
"rollback": 0.72,
216+
"rollback_new_file_e2e": 0.01,
217+
"scan": 4.26,
218+
"scan_api_retry_e2e": 2.52,
219+
"scan_get_mode_from_project_state": 0.17,
220+
"scan_pnpm_relocated_store_cwd_e2e": 0.02,
221+
"scan_requirements_lock_only": 0.66,
222+
"scan_rollout_e2e": 0.56,
223+
"scan_vendor_e2e": 0.49,
224+
"scan_vendor_requirements_unwired": 0.07,
225+
"self_update_e2e": 4.02,
226+
"self_update_failures_e2e": 4.51,
227+
"spawn_env_hygiene": 0.07,
228+
"telemetry_helpers_e2e": 0.0,
229+
"update": 4.75,
230+
"update_state_env": 0.0,
231+
"upstream_restore_golden": 1.45,
232+
"user_patches": 0.15,
233+
"uv_hosted": 0.0,
234+
"vendor": 1.93,
235+
"vendor_crash_safety_e2e": 0.09,
236+
"vendor_eject": 0.14,
237+
"vendor_eject_bun_lockb": 0.32,
238+
"vendor_eject_fresh_checkout": 0.16,
239+
"vendor_group_commit_e2e": 1.83,
240+
"vendor_jvm_cli": 0.86,
241+
"vendor_ledger_schema_e2e": 0.73,
242+
"vendor_partial_staging_e2e": 0.09,
243+
"vex": 0.06,
244+
"vlt_locks": 3.16
245+
}
246+
}

‎scripts/ci-test-shard.py‎

Lines changed: 79 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -12,13 +12,21 @@
1212
1313
Windows debug CI sets CI_TEST_TIMINGS to the checked-in runtime sample.
1414
Those shards balance measured test time plus linking work, with shard 1's
15-
unit tests reserved up front. Other runners retain the count-based split.
15+
unit tests reserved up front. Coverage shards do the same on their own
16+
Linux sample (scripts/ci-coverage-durations.json) unless CI_TEST_TIMINGS
17+
is set; setting it empty on the coverage step keeps the count split.
1618
1719
CI_TEST_COVERAGE=1 runs the shard under cargo-llvm-cov for ci.yml's
1820
`coverage` job: `cargo llvm-cov --no-report` in place of `cargo test`, and
1921
no doctests, which cargo-llvm-cov leaves out without `--doctests`. A later
2022
`cargo llvm-cov report` exports the shard's profiles.
2123
24+
Each test binary's `finished in` time is collected from cargo's output and
25+
printed at the end as one `ci-test-shard: timings {...}` JSON line, along
26+
with how long cargo took to reach its first test binary. The log tail is
27+
what log viewers and the log API return, so a fresh runtime sample can be
28+
read from any shard's log.
29+
2230
Extra arguments after `SHARD COUNT` go to every `cargo` invocation.
2331
Each invocation runs with `--no-fail-fast`; the exit status is non-zero if
2432
any of them failed.
@@ -30,13 +38,31 @@
3038
import json
3139
import os
3240
from pathlib import Path
41+
import re
3342
import subprocess
3443
import sys
44+
import threading
45+
import time
46+
47+
# The Linux runtime sample coverage shards balance on (the Windows one,
48+
# scripts/ci-test-durations.json, doesn't model them: #1768).
49+
COVERAGE_TIMINGS = Path(__file__).with_name("ci-coverage-durations.json")
3550

3651
# Shard 1's share of the integration targets, relative to every other
3752
# shard's 1.0 (it also carries the unit tests and doctests).
3853
FIRST_SHARD_WEIGHT = 0.5
3954

55+
# cargo's `Running tests/x.rs (target/debug/deps/x-0123456789abcdef)` and
56+
# `test result: ... finished in 1.23s` lines. The binary name, not the source
57+
# path, is the target name (tests/apply/main.rs is `apply`); unit-test
58+
# binaries are recorded as `unit:<crate>`. ANSI colour is stripped first.
59+
ANSI = re.compile(r"\x1b\[[0-9;]*m")
60+
RUNNING = re.compile(r"^\s*Running (unittests )?\S+ \(.*?([^/\\]+)-[0-9a-f]{16}(?:\.exe)?\)\s*$")
61+
RESULT = re.compile(r"^test result: .*finished in ([0-9.]+)s\s*$")
62+
63+
# How long run() keeps reading cargo's pipe after cargo exits.
64+
DRAIN_SECONDS = 10
65+
4066

4167
def integration_targets(metadata):
4268
"""Sorted, de-duplicated names of the workspace's integration tests."""
@@ -90,6 +116,45 @@ def invocations(shard, count, names, extra=(), timings=None, coverage=False):
90116
return runs
91117

92118

119+
def run(args, timings):
120+
"""Run `args`, echoing its merged output byte for byte, and add each test
121+
binary's `finished in` seconds to `timings`. Returns the exit status and
122+
when the first test binary started (None if none did)."""
123+
first = None
124+
125+
def forward(pipe):
126+
nonlocal first
127+
current = None
128+
echo = True
129+
for raw in pipe:
130+
# Keep draining after a failed write (say `tee` died): a reader
131+
# that stops would leave cargo blocked on a full pipe.
132+
if echo:
133+
try:
134+
sys.stdout.buffer.write(raw)
135+
sys.stdout.buffer.flush()
136+
except (OSError, ValueError):
137+
echo = False
138+
line = ANSI.sub("", raw.decode("utf-8", "replace"))
139+
if m := RUNNING.match(line):
140+
current = ("unit:" if m[1] else "") + m[2]
141+
first = first or time.monotonic()
142+
elif current and (m := RESULT.match(line)):
143+
timings[current] = timings.get(current, 0.0) + float(m[1])
144+
current = None
145+
146+
proc = subprocess.Popen(args, stdout=subprocess.PIPE, stderr=subprocess.STDOUT)
147+
reader = threading.Thread(target=forward, args=(proc.stdout,), daemon=True)
148+
reader.start()
149+
status = proc.wait()
150+
# A process a test left behind (a build daemon, say) can hold the pipe
151+
# open after cargo exits; don't wait for it past a short drain.
152+
reader.join(timeout=DRAIN_SECONDS)
153+
if not reader.is_alive():
154+
proc.stdout.close()
155+
return status, first
156+
157+
93158
def main(argv):
94159
if len(argv) < 2:
95160
print(__doc__, file=sys.stderr)
@@ -99,16 +164,26 @@ def main(argv):
99164
["cargo", "metadata", "--no-deps", "--format-version", "1"],
100165
check=True, capture_output=True, text=True).stdout)
101166
names = integration_targets(metadata)
102-
timing_path = os.environ.get("CI_TEST_TIMINGS")
103-
timings = json.loads(Path(timing_path).read_text(encoding="utf-8")) if timing_path else None
104167
coverage = os.environ.get("CI_TEST_COVERAGE") == "1"
168+
timing_path = os.environ.get("CI_TEST_TIMINGS", COVERAGE_TIMINGS if coverage else None)
169+
timings = json.loads(Path(timing_path).read_text(encoding="utf-8")) if timing_path else None
105170
print(f"ci-test-shard: shard {shard}/{count}: "
106171
f"{len(partition(names, count, timings)[shard - 1])} of {len(names)} integration targets", flush=True)
107172
status = 0
173+
measured = {}
174+
build = 0.0
108175
for args in invocations(shard, count, names, argv[2:], timings, coverage):
109176
print("+ " + " ".join(args), flush=True)
110-
if subprocess.run(args).returncode != 0:
177+
start = time.monotonic()
178+
code, first = run(args, measured)
179+
if code != 0:
111180
status = 1
181+
# Build time of this invocation: start to its first test binary.
182+
# (The doctest run prints no `Running` line and isn't counted.)
183+
if first is not None:
184+
build += first - start
185+
measured = {"_build_seconds": build, **dict(sorted(measured.items(), key=lambda kv: (-kv[1], kv[0])))}
186+
print("ci-test-shard: timings " + json.dumps({k: round(v, 2) for k, v in measured.items()}), flush=True)
112187
return status
113188

114189

0 commit comments

Comments
 (0)