Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion docs/dev/BUILD.md
Original file line number Diff line number Diff line change
Expand Up @@ -246,7 +246,7 @@ The switch combines with `APS5_TRACE_FRAMES` or `APS5_TRACE_SECONDS`. The interv

Set `APS5_TRACE_BENCH=1` together with `APS5_TRACE_SUMMARY_EVERY` to also keep every interval's frame times for a benchmark report. At each interval the presenter hands the kept intervals to a writer thread, which formats and compresses the file and rewrites `aps5-bench-<commit>-<pid>.json.gz` in `APS5_TRACE_DIR` or the working directory: one JSON object with `format` (`aps5-bench/1`), the identity fields of the summary line (`commit`, `dirty`, `env`, `gpu`, `driver`, `os`, `cpu`, `cpu_threads`, `memory_mib` and, with `param.json`, `title_id`, `title` and `content_version`), `intervals_dropped` and `intervals`. Each interval has `start_s`, `end_s`, `first_present`, `resolution`, `gpu_busy_ms` (the interval's total) and `frame_us`, the whole microseconds between consecutive presents. The file keeps the last 240 intervals; `intervals_dropped` counts older ones it no longer holds. Any other value, or the switch without `APS5_TRACE_SUMMARY_EVERY`, fails the first present. The file is written to `<name>.tmp` and then moved over the previous one, so a crash or kill during a rewrite leaves the last complete report. Only the newest report waits for the writer: one handed over while an older one is still pending replaces it. The frame times cost 4 bytes per present in memory.

`python tools/trace_digest.py aps5-summary.jsonl` prints the interval lines of such a file as one row per interval (frame p50, p90, p99, max, GPU busy per present, the busiest queue worker and the largest phase) and a text sparkline of the frame p99 and of the GPU busy time; lines of window captures in the file are skipped, and a change of commit, environment, GPU, driver or OS between intervals is reported. `--json` prints the rows as JSON.
`python tools/trace_digest.py aps5-summary.jsonl` prints the interval lines of such a file as one row per interval (frame p50, p90, p99, max, GPU busy per present, the busiest queue worker and the largest phase) and a text sparkline of the frame p99 and of the GPU busy time; lines of window captures in the file are skipped, and changes to build, environment, host, resolution or title metadata between intervals are reported. `--json` prints the rows, the first interval's identity and the indices of identity changes as JSON.

With `APS5_TRACE_SUMMARY_EVERY` set, the recorder writes a timestamp pair per batch for the whole run and every `PerformanceTimer` scope adds its time to the thread's totals, two clock reads per scope. A thread's totals are read while it runs, so a scope that straddles an interval boundary is counted in one interval or the other.

Expand Down
66 changes: 65 additions & 1 deletion tools/tests/test_trace_digest.py
Original file line number Diff line number Diff line change
Expand Up @@ -652,7 +652,71 @@ def test_identity_changes_are_reported_where_they_happen(self):
for index, commit in enumerate(("a", "a", "b", "b", "a"))]
result = trace_digest.digest_intervals(lines)
self.assertEqual(result["identity_changed_at"], [2, 4])
self.assertIn("commit, environment, GPU, driver or OS changed at interval 3, 5", trace_digest.markdown_intervals(result).splitlines())
self.assertIn("build, environment, host, resolution or title metadata changed at interval 3, 5", trace_digest.markdown_intervals(result).splitlines())

def test_machine_and_title_identity_fields_are_retained_and_compared(self):
metadata = {"cpu": "CPU A", "cpu_threads": 16, "memory_mib": 32768,
"title_id": "PPSA00001", "title": "Title One", "content_version": "01.000.000"}
first = interval_line(0.0, 30.0, 20.0, 5.0, **metadata)
for key, value in (("cpu", "CPU B"), ("cpu_threads", 32), ("memory_mib", 65536),
("title_id", "PPSA00002"), ("title", "Title Two"), ("content_version", "02.000.000")):
with self.subTest(key=key):
changed = dict(first, **{key: value})
result = trace_digest.digest_intervals([first, first, changed, changed, first])
self.assertEqual({key: result["identity"].get(key) for key in metadata}, metadata)
self.assertEqual(result["identity_changed_at"], [2, 4])
self.assertIn("changed at interval 3, 5", trace_digest.markdown_intervals(result))

def test_optional_identity_appearance_disappearance_and_return(self):
absent = interval_line(0.0, 30.0, 20.0, 5.0)
for key, value in (("cpu", "CPU A"), ("cpu_threads", 0), ("memory_mib", 0),
("title_id", "PPSA00001"), ("title", "Title One"), ("content_version", "")):
with self.subTest(key=key, value=value):
present = dict(absent, **{key: value})
result = trace_digest.digest_intervals([absent, present, present, absent, present])
self.assertEqual(result["identity_changed_at"], [1, 3, 4])
self.assertIn(key, result["identity"])
self.assertIsNone(result["identity"][key])
self.assertIn("changed at interval 2, 4, 5", trace_digest.markdown_intervals(result))

def test_stable_or_absent_optional_identity_does_not_report_changes(self):
absent = interval_line(0.0, 30.0, 20.0, 5.0)
metadata = {"cpu": "CPU A", "cpu_threads": 0, "memory_mib": 0,
"title_id": "PPSA00001", "title": "Title One", "content_version": ""}
for line in (absent, dict(absent, **metadata)):
with self.subTest(line=line):
result = trace_digest.digest_intervals([line, line])
self.assertEqual(result["identity_changed_at"], [])
self.assertNotIn("changed at interval", trace_digest.markdown_intervals(result))

def test_resolution_changes_are_reported(self):

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Note, nothing to change: resolution was already in the key tuple on main, so this pins existing detection and fails on main only because of the new wording (which now names resolution, the old message did not). Fine as a regression guard, just not one of the metadata regressions the body counts.

first = interval_line(0.0, 30.0, 20.0, 5.0)
result = trace_digest.digest_intervals([first, dict(first, resolution="1280x720")])
self.assertEqual(result["identity_changed_at"], [1])
self.assertIn("build, environment, host, resolution or title metadata changed at interval 2",
trace_digest.markdown_intervals(result))

def test_cli_retains_machine_and_title_identity_and_reports_changes(self):
metadata = {"cpu": "CPU A", "cpu_threads": 16, "memory_mib": 32768,
"title_id": "PPSA00001", "title": "Title One", "content_version": "01.000.000"}
first = interval_line(0.0, 30.0, 20.0, 5.0, **metadata)
second = interval_line(30.0, 60.0, 40.0, 10.0, **dict(metadata, content_version="02.000.000"))
self.path.write_text("\n".join(json.dumps(line) for line in (first, second)) + "\n", encoding="utf-8")
result = subprocess.run([sys.executable, trace_digest.__file__, str(self.path), "--json"],
capture_output=True, text=True, encoding="utf-8", timeout=20)
self.assertEqual(result.returncode, 0, result.stderr)
report = json.loads(result.stdout)
self.assertEqual({key: report["identity"].get(key) for key in metadata}, metadata)
self.assertEqual(report["identity_changed_at"], [1])
without_metadata = [{key: value for key, value in line.items() if key not in metadata} for line in (first, second)]
unchanged_metrics = trace_digest.digest_intervals(without_metadata)
self.assertEqual(report["intervals"], unchanged_metrics["intervals"])
result = subprocess.run([sys.executable, trace_digest.__file__, str(self.path)],
capture_output=True, text=True, encoding="utf-8", timeout=20)
self.assertEqual(result.returncode, 0, result.stderr)
self.assertIn("build, environment, host, resolution or title metadata changed at interval 2", result.stdout)
expected = trace_digest.markdown_intervals(unchanged_metrics)
self.assertEqual(result.stdout[result.stdout.index("| # |"):], expected[expected.index("| # |"):])

def test_sparkline_scales_to_the_largest_value(self):
self.assertEqual(trace_digest.sparkline([0.0, 5.0, 10.0]), ".+@")
Expand Down
5 changes: 3 additions & 2 deletions tools/trace_digest.py
Original file line number Diff line number Diff line change
Expand Up @@ -308,7 +308,8 @@ def digest_intervals(lines):
"top_phase": {"name": largest[0], "ms_per_frame": largest[1]} if largest else None,
"trace_dropped": line.get("trace_dropped", False)})
first = lines[0] if lines else {}
keys = ("commit", "dirty", "env", "gpu", "driver", "os", "resolution")
keys = ("commit", "dirty", "env", "gpu", "driver", "os", "resolution",
"cpu", "cpu_threads", "memory_mib", "title_id", "title", "content_version")
changed = [index for index in range(1, len(lines)) if any(lines[index].get(key) != lines[index - 1].get(key) for key in keys)]
return {"intervals": rows, "identity": {key: first.get(key) for key in keys}, "identity_changed_at": changed}

Expand All @@ -322,7 +323,7 @@ def markdown_intervals(result):
f"{identity['gpu']}, {identity['driver']}, {identity['os']}, {identity['resolution']}, commit {identity['commit']}"

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nit: the header still prints only GPU, driver, OS, resolution and commit, while the warning three lines down now says "host ... or title metadata changed", so a reader of a pasted digest cannot see which CPU, title or content version the trace starts with, or what changed; only --json has it. Printing title_id, title, content_version and cpu when present would close that (env was already missing here on main). If limiting the Markdown change to the warning is deliberate, a follow-up.

f"{' (dirty)' if identity.get('dirty') else ''}"]
if result["identity_changed_at"]:
lines.append("commit, environment, GPU, driver or OS changed at interval " + ", ".join(str(index + 1) for index in result["identity_changed_at"]))
lines.append("build, environment, host, resolution or title metadata changed at interval " + ", ".join(str(index + 1) for index in result["identity_changed_at"]))
lines += ["", "| # | seconds | presents | p50 | p90 | p99 | max | GPU busy | busiest worker | largest phase |", "|---|---|---|---|---|---|---|---|---|---|"]
for index, row in enumerate(rows, 1):
frame = row["frame_ms"]
Expand Down
Loading