diff --git a/scripts/ci/resource_profile.py b/scripts/ci/resource_profile.py index 9611d0a847c10..0d42376981c10 100644 --- a/scripts/ci/resource_profile.py +++ b/scripts/ci/resource_profile.py @@ -17,6 +17,8 @@ Output JSON shape: { "label": "tests slice 1/8", "duration_s": 42.3, + "started_at": "2026-01-01T00:01:00Z", # UTC bounds of the sample + "completed_at": "2026-01-01T00:01:42Z", # window, for report placement "cpu": { "avg_usage_pct": 55.2, "peak_usage_pct": 89.1, @@ -62,6 +64,7 @@ import re import signal import sys import time +from datetime import datetime, timezone _SAMPLE_INTERVAL_S = 1.0 _CLK_TICK = os.sysconf("SC_CLK_TCK") if hasattr(os, "sysconf") else 100 @@ -238,6 +241,14 @@ def run_profiler(output_path: str, label: str, timeout_s: float = 0) -> None: cpu_prev: dict | None = None start = time.monotonic() + # Wall-clock anchor for the sample window. The report needs to know WHEN + # these samples happened, not just how long they lasted: the profiler + # wraps one step, so on a job whose other steps (checkout, setup, post) + # dominate, the profiled window is a slice in the middle of the bar. + # Without this the overlay gets stretched across the whole job and the + # x-axis lies. monotonic() drives the sampling (immune to clock steps); + # this is only for placement. + started_at = datetime.now(timezone.utc) last_sample = start running = [True] # mutable for signal handler @@ -300,6 +311,13 @@ def run_profiler(output_path: str, label: str, timeout_s: float = 0) -> None: summary = { "label": label, "duration_s": round(duration_s, 1), + # ISO-8601 UTC bounds of the sample window, in the same format as + # GitHub's job/step timestamps so the report can place the series + # against a job bar's x-axis instead of stretching it to fill. + "started_at": started_at.isoformat().replace("+00:00", "Z"), + "completed_at": ( + datetime.now(timezone.utc).isoformat().replace("+00:00", "Z") + ), "cpu": { "avg_usage_pct": round(sum(cpu_samples) / n, 1), "peak_usage_pct": round(max(cpu_samples, default=0.0), 1), diff --git a/scripts/ci/timings_report.py b/scripts/ci/timings_report.py index 31dc8c4e33d0c..c9eb4c934145a 100644 --- a/scripts/ci/timings_report.py +++ b/scripts/ci/timings_report.py @@ -715,6 +715,47 @@ def _resource_overlay(profile: dict | None, expanded: bool) -> str: return f'
{"".join(layers)}
' +def _profile_window_frac(profile: dict | None, job_start, job_end) -> tuple[float, float]: + """Return (start, width) of the profiled window as fractions of the job bar. + + ``(0.0, 1.0)`` means "the whole bar" and is the fallback for every case + we cannot place confidently — that is exactly the old behaviour, so a + miss degrades to stretching rather than to a missing overlay. + + Fractions rather than percentages because the two overlay states live in + different coordinate spaces: the collapsed strip is a child of the bar, + the expanded layer sits in the track. Each scales this once, instead of + one of them undoing the other's scaling. + + Placement matters because the profiler wraps ONE step + (``.github/actions/profile``): on a job whose other steps dominate — + checkout, uv sync, post-job cleanup — the samples describe a slice in + the middle, and stretching them across the bar puts a CPU spike under a + step that never ran. + """ + if not profile or job_start is None or job_end is None: + return 0.0, 1.0 + + p_s = parse_ts(profile.get("started_at")) + p_e = parse_ts(profile.get("completed_at")) + if p_s is None or p_e is None: + return 0.0, 1.0 # artifact predates the timestamps + + span = (job_end - job_start).total_seconds() + if span <= 0: + return 0.0, 1.0 + + # Clamped into the bar: a profiler signalled just after its step ends can + # outrun the job's completed_at by a second or two. + start = max(0.0, (p_s - job_start).total_seconds() / span) + end = min(1.0, (p_e - job_start).total_seconds() / span) + if end <= start: + return 0.0, 1.0 # clock skew put the window outside the job + + # Floor keeps a hairline visible for a very short profile on a long job. + return start, max(end - start, 0.005) + + def classify_bottleneck(timings: dict, profiles: dict[str, dict]) -> str: """Return a one-line bottleneck classification. @@ -936,6 +977,11 @@ h2 { font-size: 18px; margin: 32px 0 12px; } .res-overlay { position: absolute; left: 0; width: 100%; pointer-events: none; } .res-overlay.collapsed { bottom: 0; height: 3px; } .res-overlay.expanded { top: 0; height: 100%; } +/* Positions the collapsed strip over the profiled window within the bar. + The strip itself is 100%-wide of THIS box, not of the job bar, so a job + whose profiled step is a slice in the middle shows the sparkline only + under that slice. */ +.res-clip { position: absolute; bottom: 0; height: 3px; pointer-events: none; } .res-spark { position: absolute; inset: 0; width: 100%; height: 100%; } /* Area fills so all three read stacked; the stroke on top is what actually makes each curve legible. At 3px the fill needs near-full opacity to @@ -1155,12 +1201,22 @@ def _gantt_bars(timings: dict, baseline: dict | None, seg_html = "".join(segments) - # Resource overlay. The collapsed strip is a child of the job bar - # (clipped to it, adds no row height); the expanded layer is its own - # absolutely-positioned track, sized to the bar so the x-axes agree. - # See the .res-overlay CSS for how the two states are drawn. + # Resource overlay, drawn over the PROFILED WINDOW rather than the + # whole job — see _profile_window_frac. The collapsed strip is a + # child of the bar (clipped to it, adds no row height) so it scales + # the fraction against the bar; the expanded layer is its own track + # row, so it scales against the track. profile = job_profiles.get(j["name"]) + f_left, f_width = _profile_window_frac(profile, s, e) + collapsed_overlay = _resource_overlay(profile, expanded=False) + if collapsed_overlay: + collapsed_overlay = ( + f'
' + f'{collapsed_overlay}
' + ) + expanded_overlay = "" inner = _resource_overlay(profile, expanded=True) if inner: @@ -1169,7 +1225,8 @@ def _gantt_bars(timings: dict, baseline: dict | None, f'
' f'
' f'
{inner}
' + f'style="left:{left + f_left * width:.2f}%;' + f'width:{f_width * width:.2f}%">{inner}
' f'' ) diff --git a/tests/ci/test_resource_profiles.py b/tests/ci/test_resource_profiles.py index 190c0a3a8e9d3..685f141be313d 100644 --- a/tests/ci/test_resource_profiles.py +++ b/tests/ci/test_resource_profiles.py @@ -5,10 +5,13 @@ from __future__ import annotations import importlib.util import json import os +import re import tempfile from datetime import datetime, timezone from pathlib import Path +import pytest + _PATH = Path(__file__).resolve().parents[2] / "scripts" / "ci" / "timings_report.py" _spec = importlib.util.spec_from_file_location("timings_report", _PATH) if _spec is None or _spec.loader is None: @@ -401,3 +404,79 @@ def test_gantt_overlay_survives_profiles_without_series(): html = _mod.generate_html(t, None, {"tests-slice-1": _profile("tests-slice-1")}) assert 'class="res-overlay' not in html assert "Resource Usage" in html + + +# ── overlay placement: profiled window, not the whole job ─────────────── +# +# The profiler wraps ONE step, so on a job dominated by checkout/setup/post +# the samples cover a slice in the middle of the bar. Stretching them to the +# full bar puts a CPU spike under a step that never ran. + +_FULL_BAR = (0.0, 1.0) + + +def _window(profile, job_start_s=0.0, job_dur_s=100.0): + """(start, width) of the overlay as fractions of the job bar.""" + return _mod._profile_window_frac( + profile, + _mod.parse_ts(_ts(job_start_s)), + _mod.parse_ts(_ts(job_start_s + job_dur_s)), + ) + + +def _profiled(start_s: float | None = None, end_s: float = 0.0): + p = _with_series("tests", [1, 2], [3, 4], [5, 6]) + if start_s is not None: + p["started_at"], p["completed_at"] = _ts(start_s), _ts(end_s) + return p + + +def test_overlay_spans_only_the_profiled_slice_of_the_job(): + """A 30s profile inside a 100s job covers 60%..90%, not the whole bar.""" + assert _window(_profiled(60, 90)) == pytest.approx((0.6, 0.3)) + + +def test_overlay_placement_is_relative_to_the_jobs_own_start(): + """Offsets are measured from the job's start, not the run's.""" + assert _window(_profiled(250, 275), job_start_s=200.0) == pytest.approx((0.5, 0.25)) + + +def test_overlay_falls_back_to_full_bar_without_timestamps(): + """Profiles predating started_at/completed_at keep the old behaviour.""" + p = _profiled() + assert "started_at" not in p + assert _window(p) == _FULL_BAR + + +def test_overlay_falls_back_when_window_misses_the_job(): + """Clock skew that puts the window outside the job must not vanish it.""" + assert _window(_profiled(9000, 9030)) == _FULL_BAR + + +def test_overlay_clamps_a_profiler_that_outran_the_job(): + """A profile ending after the job's completed_at is clipped to the bar.""" + start, width = _window(_profiled(60, 150)) + assert (start, start + width) == pytest.approx((0.6, 1.0)) + + +def test_overlay_keeps_a_hairline_for_a_very_short_profile(): + """A sub-percent window stays visible rather than collapsing to nothing.""" + assert _window(_profiled(50, 50.01))[1] >= 0.005 + + +def test_gantt_positions_both_overlay_states_over_the_same_window(): + """The in-bar strip and the expanded layer must agree on the x-axis.""" + t = _timings([_job("Python tests / Run tests slice 1/8", 100.0)]) + p = _profiled(60, 90) + p["label"] = "tests-slice-1" + + html = _mod.generate_html(t, None, {"tests-slice-1": p}) + + geom = { + kind: (round(float(l)), round(float(w))) + for kind, l, w in re.findall( + r'res-(holder|clip)[^>]*style="left:([\d.]+)%;width:([\d.]+)%"', html + ) + } + # The job spans the whole run here, so bar- and track-relative agree. + assert geom == {"holder": (60, 30), "clip": (60, 30)}, html[:400]