fix(skill-creator): tolerate malformed timing measurements (#7078)

* fix(skill-creator): tolerate non-object timing measurements

Treat optional timing JSON values that are not objects as missing measurements so they cannot abort benchmark aggregation. Preserve grading durations, character-count fallback and recorded zeros; add regression coverage for both layouts and subsequent runs.

* fix(skill-creator): warn and validate timing measurements

* fix(skill-creator): tolerate unreadable timing files

---------

Co-authored-by: Willem Jiang <willem.jiang@gmail.com>
This commit is contained in:
MsNBBc3R 2026-10-20 08:30:37 +08:00 committed by GitHub
parent 18ca09b2da
commit 2259df1130
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
4 changed files with 334 additions and 10 deletions

View File

@ -1503,6 +1503,11 @@ Skill Markdown and bundled text resources use UTF-8. Skill-creator CLI and revie
Skill-creator benchmark aggregation uses recorded `timing.json` token counts even
when `grading.json` already contains the run duration. Recorded zero counts are
preserved; output character counts remain a legacy proxy only when token data is missing.
Unreadable, non-UTF-8, malformed, or non-object `timing.json` data emits a warning
and is treated as missing measurements. Its token and duration fields accept finite,
non-negative numbers (including zero); invalid fields emit a warning naming the file
and field and use the existing fallback independently, preserving valid measurements
and other runs.
`SKILL.md` YAML frontmatter must open and close with `---` on its own line (trailing spaces or tabs are allowed). A line such as `---suffix` is not a closing delimiter.

View File

@ -297,7 +297,9 @@ Output from Benchmark mode. Located at `benchmarks/<timestamp>/benchmark.json`.
- `configuration`: Must be `"with_skill"` or `"without_skill"` (the viewer uses this exact string for grouping and color coding)
- `run_number`: Integer run number (1, 2, 3...)
- `result`: Nested object with `pass_rate`, `passed`, `total`, `time_seconds`, `tokens`, `errors`
- `tokens`: Uses sibling `timing.json.total_tokens` when present (including zero), independently of duration fields in `grading.json`. If the token count is missing or null, aggregation retains the legacy `execution_metrics.output_chars` proxy, defaulting to zero if that is also missing.
- `tokens`: Uses sibling `timing.json.total_tokens` when it is a finite, non-negative number (including zero), independently of duration fields in `grading.json`. If missing, null, or invalid, aggregation retains the legacy `execution_metrics.output_chars` proxy, defaulting to zero if that is also missing.
- `time_seconds`: Preserves the grading duration. When it is zero or absent, uses a finite, non-negative `timing.json.total_duration_seconds`, otherwise zero. Timing fields are validated independently, so an invalid duration does not discard valid tokens and vice versa.
- An unreadable or non-UTF-8 `timing.json`, malformed JSON, a non-object document, or an invalid timing field emits a warning identifying the file (and field, where applicable). Strings, booleans, arrays, objects, negative values, and non-finite numbers are invalid measurements. Missing or null fields use their fallbacks without a warning. Other runs continue to be aggregated.
- `run_summary`: Statistical aggregates per configuration
- `with_skill` / `without_skill`: Each contains `pass_rate`, `time_seconds`, `tokens` objects with `mean` and `stddev` fields
- `delta`: Difference strings like `"+0.50"`, `"+13.0"`, `"+1700"`

View File

@ -64,6 +64,22 @@ def calculate_stats(values: list[float]) -> dict:
}
def _read_timing_number(timing_data: dict, key: str, timing_file: Path) -> int | float | None:
"""Read an optional measurement without admitting invalid values to statistics."""
value = timing_data.get(key)
if value is None:
return None
if (
isinstance(value, bool)
or not isinstance(value, (int, float))
or value < 0
or (isinstance(value, float) and not math.isfinite(value))
):
print(f"Warning: ignoring invalid {key} in {timing_file}; expected a finite non-negative number")
return None
return value
def load_run_results(benchmark_dir: Path) -> dict:
"""
Load all run results from a benchmark directory.
@ -137,15 +153,19 @@ def load_run_results(benchmark_dir: Path) -> dict:
timing = grading.get("timing", {})
result["time_seconds"] = timing.get("total_duration_seconds", 0.0)
timing_file = run_dir / "timing.json"
if timing_file.exists():
try:
try:
if timing_file.exists():
with open(timing_file, encoding="utf-8") as tf:
timing_data = json.load(tf)
if not isinstance(timing_data, dict):
print(f"Warning: ignoring non-object timing data in {timing_file}")
timing_data = {}
duration = _read_timing_number(timing_data, "total_duration_seconds", timing_file)
if result["time_seconds"] == 0.0:
result["time_seconds"] = timing_data.get("total_duration_seconds", 0.0)
result["tokens"] = timing_data.get("total_tokens")
except json.JSONDecodeError:
pass
result["time_seconds"] = duration if duration is not None else 0.0
result["tokens"] = _read_timing_number(timing_data, "total_tokens", timing_file)
except (json.JSONDecodeError, UnicodeDecodeError, OSError) as e:
print(f"Warning: Unable to read timing data in {timing_file}: {e}")
# Extract metrics if available
metrics = grading.get("execution_metrics", {})

View File

@ -1,7 +1,10 @@
"""Regressions for skill-creator benchmark measurements."""
import builtins
import json
import runpy
import subprocess
import sys
from pathlib import Path
import pytest
@ -16,8 +19,10 @@ def benchmark_script():
return runpy.run_path(str(script))
def write_run(root, *, grading_timing=None, timing=None, config="with_skill"):
run_dir = root / "eval-1" / config / "run-1"
def write_run(
root, *, grading_timing=None, timing=None, config="with_skill", run_number=1
):
run_dir = root / "eval-1" / config / f"run-{run_number}"
run_dir.mkdir(parents=True)
grading = {
"summary": {"pass_rate": 1.0, "passed": 1, "failed": 0, "total": 1},
@ -75,7 +80,7 @@ def test_recorded_tokens_preserved_in_both_layouts(
)
@pytest.mark.parametrize("has_grading_duration", [False, True])
def test_missing_token_measurements_keep_legacy_character_fallback(
tmp_path, benchmark_script, timing_state, has_grading_duration
tmp_path, benchmark_script, timing_state, has_grading_duration, capsys
):
grading_timing = {"total_duration_seconds": 23.3} if has_grading_duration else None
timing = None
@ -92,6 +97,298 @@ def test_missing_token_measurements_keep_legacy_character_fallback(
assert benchmark["runs"][0]["result"]["tokens"] == 12450
expected_time = 23.3 if has_grading_duration else (25.0 if timing else 0.0)
assert benchmark["runs"][0]["result"]["time_seconds"] == expected_time
output = capsys.readouterr().out
if timing_state == "invalid_json":
assert "Warning:" in output
assert str(run_dir / "timing.json") in output
else:
assert output == ""
@pytest.mark.parametrize("layout", ["workspace", "legacy"])
@pytest.mark.parametrize("has_grading_duration", [False, True])
@pytest.mark.parametrize(
"timing_data",
[None, [], [{"total_tokens": 84852}], "timing", 42, False],
ids=["null", "empty-array", "array", "string", "number", "boolean"],
)
def test_non_object_timing_keeps_fallback_and_other_runs(
tmp_path, benchmark_script, layout, has_grading_duration, timing_data, capsys
):
root = tmp_path / "runs" if layout == "legacy" else tmp_path
grading_timing = {"total_duration_seconds": 23.3} if has_grading_duration else None
run_dir = write_run(root, grading_timing=grading_timing)
(run_dir / "timing.json").write_text(json.dumps(timing_data), encoding="utf-8")
write_run(
root,
timing={"total_duration_seconds": 25.0, "total_tokens": 0},
config="without_skill",
)
benchmark = benchmark_script["generate_benchmark"](tmp_path)
results = {run["configuration"]: run["result"] for run in benchmark["runs"]}
assert set(results) == {"with_skill", "without_skill"}
assert results["with_skill"]["tokens"] == 12450
assert results["with_skill"]["time_seconds"] == (
23.3 if has_grading_duration else 0.0
)
assert results["without_skill"]["tokens"] == 0
assert results["without_skill"]["time_seconds"] == 25.0
assert benchmark["run_summary"]["with_skill"]["tokens"]["mean"] == 12450
assert benchmark["run_summary"]["delta"]["tokens"] == "+12450"
assert "| Tokens | 12450 ± 0 | 0 ± 0 | +12450 |" in benchmark_script[
"generate_markdown"
](benchmark)
output = capsys.readouterr().out
assert "Warning:" in output
assert "non-object" in output
assert str(run_dir / "timing.json") in output
@pytest.mark.parametrize("layout", ["workspace", "legacy"])
@pytest.mark.parametrize("has_grading_duration", [False, True])
@pytest.mark.parametrize("field", ["total_tokens", "total_duration_seconds"])
@pytest.mark.parametrize(
"value",
[
"84852",
{"n": 1},
[],
True,
False,
-1,
-0.5,
float("nan"),
float("inf"),
-float("inf"),
],
ids=[
"string",
"object",
"array",
"true",
"false",
"negative-int",
"negative-float",
"nan",
"infinity",
"negative-infinity",
],
)
def test_invalid_timing_field_warns_and_preserves_other_measurements(
tmp_path, benchmark_script, layout, has_grading_duration, field, value, capsys
):
root = tmp_path / "runs" if layout == "legacy" else tmp_path
timing = {"total_tokens": 0, "total_duration_seconds": 25.0, field: value}
grading_timing = {"total_duration_seconds": 23.3} if has_grading_duration else None
run_dir = write_run(root, grading_timing=grading_timing, timing=timing)
write_run(
root, timing={"total_tokens": 0, "total_duration_seconds": 25.0}, run_number=2
)
benchmark = benchmark_script["generate_benchmark"](tmp_path)
results = {run["run_number"]: run["result"] for run in benchmark["runs"]}
assert set(results) == {1, 2}
expected_tokens = 12450 if field == "total_tokens" else 0
expected_time = (
23.3
if has_grading_duration
else (0.0 if field == "total_duration_seconds" else 25.0)
)
assert results[1]["tokens"] == expected_tokens
assert results[1]["time_seconds"] == expected_time
assert results[2]["tokens"] == 0
assert results[2]["time_seconds"] == 25.0
summary = benchmark["run_summary"]["with_skill"]
assert summary["tokens"]["mean"] == expected_tokens / 2
assert summary["time_seconds"]["mean"] == (expected_time + 25.0) / 2
assert "| Tokens |" in benchmark_script["generate_markdown"](benchmark)
json.dumps(benchmark, allow_nan=False)
output = capsys.readouterr().out
assert "Warning:" in output
assert field in output
assert str(run_dir / "timing.json") in output
@pytest.mark.parametrize("tokens", [0, 0.0, 84852, 12.5])
@pytest.mark.parametrize("duration", [0, 0.0, 25.0])
def test_finite_non_negative_timing_numbers_are_preserved(
tmp_path, benchmark_script, tokens, duration, capsys
):
write_run(
tmp_path, timing={"total_tokens": tokens, "total_duration_seconds": duration}
)
benchmark = benchmark_script["generate_benchmark"](tmp_path)
assert benchmark["runs"][0]["result"]["tokens"] == tokens
assert benchmark["runs"][0]["result"]["time_seconds"] == duration
assert benchmark["run_summary"]["with_skill"]["tokens"]["mean"] == tokens
assert capsys.readouterr().out == ""
@pytest.mark.parametrize("has_grading_duration", [False, True])
@pytest.mark.parametrize(
"timing",
[
{},
{"total_tokens": None},
{"total_duration_seconds": None},
{"total_tokens": None, "total_duration_seconds": None},
],
)
def test_missing_or_null_timing_fields_use_fallbacks_without_warning(
tmp_path, benchmark_script, has_grading_duration, timing, capsys
):
grading_timing = {"total_duration_seconds": 23.3} if has_grading_duration else None
write_run(tmp_path, grading_timing=grading_timing, timing=timing)
benchmark = benchmark_script["generate_benchmark"](tmp_path)
assert benchmark["runs"][0]["result"]["tokens"] == 12450
assert benchmark["runs"][0]["result"]["time_seconds"] == (
23.3 if has_grading_duration else 0.0
)
assert capsys.readouterr().out == ""
@pytest.mark.parametrize("layout", ["workspace", "legacy"])
@pytest.mark.parametrize("has_grading_duration", [False, True])
@pytest.mark.parametrize(
"timing_content,expected_tokens,expected_duration",
[
("null", 12450, 0.0),
("{invalid", 12450, 0.0),
(b"\xff\xfe{invalid", 12450, 0.0),
(None, 12450, 0.0),
('{"total_tokens": "84852", "total_duration_seconds": 25.0}', 12450, 25.0),
('{"total_tokens": 0, "total_duration_seconds": {"n": 1}}', 0, 0.0),
('{"total_tokens": false, "total_duration_seconds": true}', 12450, 0.0),
],
ids=[
"non-object",
"invalid-json",
"invalid-utf8",
"directory",
"invalid-tokens",
"invalid-duration",
"both-invalid",
],
)
def test_cli_warns_and_writes_reports_for_invalid_timing(
tmp_path,
benchmark_script,
layout,
has_grading_duration,
timing_content,
expected_tokens,
expected_duration,
):
root = tmp_path / "runs" if layout == "legacy" else tmp_path
grading_timing = {"total_duration_seconds": 23.3} if has_grading_duration else None
run_dir = write_run(root, grading_timing=grading_timing)
timing_file = run_dir / "timing.json"
if timing_content is None:
timing_file.mkdir()
elif isinstance(timing_content, bytes):
timing_file.write_bytes(timing_content)
else:
timing_file.write_text(timing_content, encoding="utf-8")
write_run(
root,
timing={"total_tokens": 0, "total_duration_seconds": 25.0},
config="without_skill",
)
completed = subprocess.run(
[sys.executable, benchmark_script["__file__"], str(tmp_path)],
capture_output=True,
text=True,
encoding="utf-8",
timeout=30,
)
assert completed.returncode == 0, completed.stderr
assert "Warning:" in completed.stdout
assert str(run_dir / "timing.json") in completed.stdout
benchmark = json.loads((tmp_path / "benchmark.json").read_text(encoding="utf-8"))
results = {run["configuration"]: run["result"] for run in benchmark["runs"]}
assert set(results) == {"with_skill", "without_skill"}
assert results["with_skill"]["tokens"] == expected_tokens
assert results["with_skill"]["time_seconds"] == (
23.3 if has_grading_duration else expected_duration
)
assert results["without_skill"]["tokens"] == 0
assert results["without_skill"]["time_seconds"] == 25.0
assert (tmp_path / "benchmark.md").read_text(encoding="utf-8") == benchmark_script[
"generate_markdown"
](benchmark)
@pytest.mark.parametrize("layout", ["workspace", "legacy"])
@pytest.mark.parametrize("has_grading_duration", [False, True])
@pytest.mark.parametrize("operation", ["open", "exists"])
def test_unreadable_timing_warns_and_keeps_fallback_and_other_runs(
tmp_path,
benchmark_script,
layout,
has_grading_duration,
operation,
monkeypatch,
capsys,
):
root = tmp_path / "runs" if layout == "legacy" else tmp_path
grading_timing = {"total_duration_seconds": 23.3} if has_grading_duration else None
run_dir = write_run(
root,
grading_timing=grading_timing,
timing={"total_tokens": 84852, "total_duration_seconds": 25.0},
)
timing_file = run_dir / "timing.json"
write_run(
root,
timing={"total_tokens": 0, "total_duration_seconds": 25.0},
config="without_skill",
)
# Inject access failures without relying on OS permissions or the test user's UID.
if operation == "open":
original_open = builtins.open
def denied_open(file, *args, **kwargs):
if file == timing_file:
raise PermissionError("timing access denied")
return original_open(file, *args, **kwargs)
monkeypatch.setattr(builtins, "open", denied_open)
else:
original_exists = Path.exists
def denied_exists(path, *args, **kwargs):
if path == timing_file:
raise PermissionError("timing access denied")
return original_exists(path, *args, **kwargs)
monkeypatch.setattr(Path, "exists", denied_exists)
benchmark = benchmark_script["generate_benchmark"](tmp_path)
results = {run["configuration"]: run["result"] for run in benchmark["runs"]}
assert set(results) == {"with_skill", "without_skill"}
assert results["with_skill"]["tokens"] == 12450
assert results["with_skill"]["time_seconds"] == (
23.3 if has_grading_duration else 0.0
)
assert results["without_skill"]["tokens"] == 0
assert results["without_skill"]["time_seconds"] == 25.0
assert benchmark["run_summary"]["delta"]["tokens"] == "+12450"
assert "| Tokens |" in benchmark_script["generate_markdown"](benchmark)
json.dumps(benchmark, allow_nan=False)
output = capsys.readouterr().out
assert "Warning:" in output
assert str(timing_file) in output
assert "timing access denied" in output
def test_recorded_tokens_propagate_to_summary_delta_and_markdown(