Files
SystemSimulationApp/tests/manual/summarize_web_cost.py
T
lujingze 3bc4be3c06 优化原生结果编码传输与浏览器缓存,记录八路性能基线
原生结果series通过字节索引直传,C端使用Ryu精确回读编码和64 KiB批量写出;网页采用Float64缓存和CSV工作线程,减少结果处理与保存等待。

补充八路AME曲线核查、全流程分阶段计时、独立编码基准和复现工具,固定后续优化采用修正八路及rtol=1e-8。C写出1.1808→0.1638 s,点击到可查看8.0100→6.9756 s。

验证:最终10项编码专项、29项相关后端回归通过;8份原生结果逐位一致,16次网页结果/CSV/刷新恢复通过。前端构建及缓存/CSV专项在本轮结果处理工作中通过。环境、原始大结果与临时构建不纳入Git。
2026-09-11 15:09:15 +00:00

386 lines
27 KiB
Python

"""Summarize one web-cost experiment without reading numerical result files.
Usage: .venv/bin/python tests/manual/summarize_web_cost.py --root test/web-cost-20260911
Only small summary/trace/stages/environment JSON files are read. Warmups and
control/profiled groups stay separate. This script does not compute speedups.
"""
from __future__ import annotations
import argparse
import csv
import hashlib
import json
import math
from pathlib import Path
from statistics import median
from typing import Any
REPO = Path(__file__).resolve().parents[2]
AXIS = (
("runClick", "click"), ("fetchStart", "fetch"), ("headers", "headers"),
("lastChunk", "last_chunk"), ("resultParseStart", "parse_start"),
("resultParseEnd", "parse_end"), ("streamEof", "eof"),
("resultReadyDom", "ready"), ("indexedDbCommittedPointer", "commit"),
)
# Prune the reporting tree at these declared boundaries. The indexed-read and
# process-lifetime spans are atomic ONLY in this coarse HTTP partition; their
# measured children remain visible in the separate inclusive span hierarchy.
HTTP_BOUNDARIES = {
"xml_validation", "network_compilation", "c_generation",
"native_build_or_cache_validation", "native_process_lifetime_observed",
"native_indexed_result_read", "profile_artifact_preservation",
"response_result_json_serialization",
}
C_WALL_FIELDS = (
"argumentPreparationSeconds", "initializationSeconds", "integrationSeconds",
"finalSampleAndStatusSeconds", "projectionSeconds", "jsonWriteSeconds",
)
DEFINITIONS = {
"scope": "One current experiment; control/profiled are observation modes, not before/after implementations. No speedup is computed.",
"statistics": "Median/min/max are calculated from individual runs. Percentages divide each run by its own stated denominator before aggregation. Medians need not add to a median total.",
"warmup": "All warmup rows are retained separately and excluded from measured statistics. Cold build is identified by cacheHit=false, not by the warmup label.",
"frontendClock": "Browser performance.now() within one trace timeOrigin. Reload/restore has another time axis; no timestamps are subtracted across documents or across browser/backend clocks.",
"waterfall": "Adjacent requested marks are subtracted without clipping negatives. Missing marks remain null; commit is the instrumented pointer publication, never replaced by the control polling mark.",
"waterfallPercent": "Each adjacent interval / same-run click-to-commit. Negative intervals remain negative and reveal overlapping completion order; they are not exclusive CPU costs.",
"backendClock": "Backend spans use request-relative perf_counter_ns. Parent links are inferred by interval containment and indicate inclusive wall intervals, not a traced call stack or exclusive CPU work.",
"httpPartition": "Pruned reporting leaves use HTTP_BOUNDARIES, checked for overlap and containment before partitioning. Their union is subtracted from HTTP total to produce unnamed other time. Spawn/read/parse children must not be added again. Response assembly has a duration but no aligned timestamp and remains in other.",
"backendOther": "Unclassified HTTP wall intervals include uninstrumented work, scheduling, response assembly, inter-stage gaps and sending. They are not all transport time or CPU work.",
"process": "Observed lifetime runs from Popen entry to the first existing poll/wait reporting exit; includes spawn and exit-observation delay. The result processWallSeconds also includes Python result reading. Child CPU is a RUSAGE_CHILDREN delta and assumes no unrelated child is reaped in the same parent interval.",
"cInitialization": "The separately measured initialization covers model_init and first sample. CVODE allocation/init/reinit and cleanup are inside integration, along with RHS, Jacobian/linear solve, events and sampling.",
"cOutput": "Projection includes final/sample model_eval and allocation. JSON write includes float formatting, stdio, file close and index writing. CPU and wall are separately reported; their difference is not a measured disk-I/O stage.",
"cParent": "C phase wall percentages use same-run C main wall; CPU percentages use the same-run observed child user+system CPU. Initial/final/remaining CPU is not individually measured.",
"stream": "Read-wait wall overlaps backend production/transport/browser scheduling. Decode and JSON.parse are within headers-to-EOF. NDJSON scanning/join/trim, callbacks, GC and scheduler time are not independently timed.",
"persistence": "Save preparation/IndexedDB run in the background with readiness and rendering. Transaction windows include asynchronous waiting; pointer commit is publication after successful writes, control observation uses polling.",
"renderExport": "Two requestAnimationFrame callbacks give a paint opportunity, not GPU completion. Download completion includes automation delivery and saveAs. CSV Worker transfer/preparation overlaps Worker activity; finish-post-to-receipt is not isolated Worker CPU.",
"unmeasured": "No exclusive breakdown of click preprocessing, NDJSON join/trim, React/GC, CVODE internals, C formatting versus file writes, browser network stack or GPU work is invented. Deeper/native-only experiments are intentionally not read here.",
}
def number(value: Any) -> bool:
return type(value) in (int, float) and math.isfinite(value)
def ratio(value: Any, denominator: Any) -> float | None:
return 100.0 * value / denominator if number(value) and number(denominator) and denominator > 0 else None
def difference(marks: dict, left: str, right: str) -> float | None:
a, b = marks.get(left), marks.get(right)
return b - a if number(a) and number(b) else None
def statistics(values: list[Any]) -> dict:
valid = [float(value) for value in values if number(value)]
return {"count": len(valid), "missingCount": len(values) - len(valid),
"median": median(valid) if valid else None,
"min": min(valid) if valid else None, "max": max(valid) if valid else None,
"values": values}
def union_length(intervals: list[tuple[float, float]]) -> float:
total, end = 0.0, -math.inf
for start, stop in sorted(intervals):
total += max(0.0, stop - max(start, end))
end = max(end, stop)
return total
def span_hierarchy(raw_spans: list[dict], http_ms: float) -> list[dict]:
spans = [{"id": "http", "name": "http_total", "startMs": 0.0,
"endMs": http_ms, "durationMs": http_ms, "source": "httpTotalSeconds"}]
for index, span in enumerate(raw_spans):
start, end = span.get("startMs"), span.get("endMs")
if not number(start) or not number(end) or end < start:
raise ValueError(f"Invalid backend span: {span}")
spans.append({"id": f"span-{index}", "name": span["name"], "startMs": start,
"endMs": end, "durationMs": end - start,
"recordedSeconds": span.get("seconds"), "source": "spans"})
for current in spans:
candidates = [other for other in spans if other["id"] != current["id"]
and other["startMs"] <= current["startMs"]
and other["endMs"] >= current["endMs"]
and (other["durationMs"] > current["durationMs"]
or other["id"] == "http")]
parent = min(candidates, key=lambda s: s["durationMs"]) if current["id"] != "http" and candidates else None
current["parentId"] = parent["id"] if parent else None
current["parentName"] = parent["name"] if parent else None
current["percentOfParent"] = ratio(current["durationMs"], parent["durationMs"]) if parent else None
current["percentOfHttp"] = ratio(current["durationMs"], http_ms)
current["inclusion"] = "inclusive interval; do not add its children"
for current in spans:
children = [s for s in spans if s["parentId"] == current["id"]]
current["children"] = [s["id"] for s in children]
current["uncoveredByDirectChildrenMs"] = current["durationMs"] - union_length(
[(s["startMs"], s["endMs"]) for s in children])
current["partiallyOverlaps"] = [s["id"] for s in spans if s["id"] != current["id"]
and max(s["startMs"], current["startMs"]) < min(s["endMs"], current["endMs"])
and not (s["startMs"] <= current["startMs"] and s["endMs"] >= current["endMs"])
and not (current["startMs"] <= s["startMs"] and current["endMs"] >= s["endMs"])]
return spans
class Summary:
def __init__(self, root: Path):
self.root = root.resolve()
self.sources: dict[str, dict] = {}
self.observations: list[dict] = []
self.warnings: list[str] = []
def read(self, path: Path) -> dict:
path = path.resolve()
path.relative_to(self.root)
size = path.stat().st_size
if size > 4 * 1024 * 1024:
raise ValueError(f"Expected small metadata JSON, refusing {path} ({size} bytes)")
raw = path.read_bytes()
self.sources[str(path.relative_to(self.root))] = {
"sha256": hashlib.sha256(raw).hexdigest(), "bytes": len(raw)}
return json.loads(raw)
def observe(self, run: dict, domain: str, metric: str, value: Any,
unit: str = "ms", *, parent: str = "", denominator: Any = None,
inclusion: str = "inclusive or overlapping; not additive", source: str = "") -> None:
if value is not None and not number(value):
raise ValueError(f"Non-numeric metric {domain}.{metric}: {value!r}")
self.observations.append({"group": run["group"], "phase": run["phase"],
"run": run["run"], "simulationId": run["simulationId"], "domain": domain,
"metric": metric, "value": value, "unit": unit, "parent": parent,
"denominatorValue": denominator if number(denominator) else None,
"percentOfParent": ratio(value, denominator), "inclusion": inclusion, "source": source})
def backend(self, run: dict, data: dict, source: str) -> dict:
if data.get("id") != run["simulationId"]:
raise ValueError(f"Simulation ID mismatch in {source}")
http_ms = data["httpTotalSeconds"] * 1000
hierarchy = span_hierarchy(data.get("spans", []), http_ms)
by_name: dict[str, list[dict]] = {}
for span in hierarchy:
by_name.setdefault(span["name"], []).append(span)
for name, occurrences in by_name.items():
parent_names = sorted({s["parentName"] or "" for s in occurrences})
self.observe(run, "backend_spans", name, sum(s["durationMs"] for s in occurrences),
parent="http_total", denominator=http_ms, source=source,
inclusion=f"inclusive sum of {len(occurrences)} call(s); interval parents: {', '.join(parent_names)}")
chosen = [s for s in hierarchy if s["name"] in HTTP_BOUNDARIES]
intervals = [(s["startMs"], s["endMs"]) for s in chosen]
covered = union_length(intervals)
overlaps = sum(stop - start for start, stop in intervals) - covered
outside = [s["id"] for s in chosen if s["startMs"] < 0 or s["endMs"] > http_ms]
partition_ok = overlaps <= 1e-6 and not outside
partition = {"valid": partition_ok, "scope": "http_total", "totalMs": http_ms,
"selectedSpanIds": [s["id"] for s in chosen], "measuredUnionMs": covered,
"overlapMs": overlaps, "outsideHttpSpanIds": outside,
"otherMs": http_ms - covered if not outside else None,
"note": DEFINITIONS["httpPartition"], "segments": []}
if partition_ok:
partition_durations: dict[str, float] = {}
for span in sorted(chosen, key=lambda s: s["startMs"]):
partition["segments"].append({"metric": span["name"], "startMs": span["startMs"],
"endMs": span["endMs"], "durationMs": span["durationMs"],
"percentOfHttp": ratio(span["durationMs"], http_ms)})
partition_durations[span["name"]] = partition_durations.get(span["name"], 0) + span["durationMs"]
for name, duration in partition_durations.items():
self.observe(run, "http_partition", name, duration,
parent="http_total", denominator=http_ms, inclusion="non-overlapping at declared reporting depth", source=source)
self.observe(run, "http_partition", "other_unclassified", partition["otherMs"],
parent="http_total", denominator=http_ms, inclusion=DEFINITIONS["backendOther"], source=source)
else:
self.warnings.append(f"{run['simulationId']}: HTTP partition disabled; selected spans overlap or leave request bounds")
for key, value in data.items():
if key.endswith("Ms") or key in ("responseBodyBytes", "rawSeriesBytes", "xmlBytes", "sampleCount"):
self.observe(run, "backend_metrics", key, value,
"ms" if key.endswith("Ms") else "bytes" if key.endswith("Bytes") else "count", source=source)
elif key == "responseSendAwaitSeconds":
self.observe(run, "backend_metrics", key, value * 1000,
inclusion="ASGI send waits overlap HTTP and are not pure network time", source=source)
phases = data.get("existingPerformance", {}).get("phases", {})
for key, phase in phases.items():
self.observe(run, "backend_existing_performance", key, phase["inclusiveNs"] / 1e6,
parent="http_total", denominator=http_ms, source=source,
inclusion="inclusive duration without aligned start/end; excluded from HTTP partition")
c = dict(data.get("nativeStages", {}))
native = data.get("native", {})
c_main = c.get("mainTotalSeconds")
for key in C_WALL_FIELDS:
value = c.get(key)
self.observe(run, "c_wall", key, value * 1000 if number(value) else None,
parent="c_main_wall", denominator=c_main * 1000 if number(c_main) else None,
inclusion="sequential C phase wall duration; C main lies within observed process lifetime", source=source)
self.observe(run, "c_wall", "mainTotalSeconds", c_main * 1000 if number(c_main) else None,
inclusion="inclusive C main; does not include loader/exit observation", source=source)
c_other = c_main - sum(c[key] for key in C_WALL_FIELDS) if number(c_main) and all(number(c.get(k)) for k in C_WALL_FIELDS) else None
self.observe(run, "c_wall", "other_unclassified", c_other * 1000 if number(c_other) else None,
parent="c_main_wall", denominator=c_main * 1000 if number(c_main) else None,
inclusion="C main minus sequential measured wall phases, without clipping negative differences", source=source)
process = dict(data.get("process", {}))
child_cpu = (process["childrenUserCpuSeconds"] + process["childrenSystemCpuSeconds"]
if all(number(process.get(k)) for k in ("childrenUserCpuSeconds", "childrenSystemCpuSeconds")) else None)
for key, value in {"integrationCpuSeconds": native.get("solveCpuSeconds"),
"projectionCpuSeconds": c.get("projectionCpuSeconds"),
"jsonWriteCpuSeconds": c.get("jsonWriteCpuSeconds")}.items():
self.observe(run, "c_cpu", key, value * 1000 if number(value) else None,
parent="observed_child_cpu", denominator=child_cpu * 1000 if number(child_cpu) else None,
inclusion="CPU duration, separate from wall partition", source=source)
for key in ("startMs", "exitObservedMs", "childrenUserCpuSeconds", "childrenSystemCpuSeconds"):
value = process.get(key)
self.observe(run, "process", key, value * 1000 if number(value) and key.endswith("Seconds") else value,
inclusion=DEFINITIONS["process"], source=source)
self.observe(run, "process", "observed_lifetime", difference(process, "startMs", "exitObservedMs"),
inclusion="includes spawn; excludes subsequent Python result read", source=source)
self.observe(run, "process", "observed_child_cpu", child_cpu * 1000 if number(child_cpu) else None,
inclusion=DEFINITIONS["process"], source=source)
return {"source": source, "httpTotalMs": http_ms, "spanHierarchy": hierarchy,
"httpPartition": partition, "cStages": c, "process": process,
"build": data.get("build"), "native": native,
"existingPerformance": data.get("existingPerformance")}
def group(self, mode: str, expected_runs: int) -> dict:
folder = self.root / f"browser-{mode}"
source = folder / "summary.json"
summary = self.read(source)
rows = summary.get("rows", [])
seen: set[str] = set()
runs = []
for original in rows:
if original.get("mode") != mode:
raise ValueError(f"Unexpected mode {original.get('mode')!r} in {source}")
sid = original["simulationId"]
if sid in seen:
raise ValueError(f"Duplicate simulationId {sid} in {source}")
seen.add(sid)
run = {"group": mode, "phase": "warmup" if original.get("warmup") else "measured",
"run": original["run"], "simulationId": sid, "original": original}
trace_path = folder / original["artifacts"] / "trace.json"
trace = self.read(trace_path)
if trace.get("timeOrigin") != original.get("timeOrigin"):
raise ValueError(f"Browser timeOrigin mismatch: {trace_path}")
marks = trace.get("marks", {})
if mode == "profiled":
request_ids = {r.get("simulationId") for r in trace.get("requests", []) if r.get("kind") == "simulation"}
if request_ids != {sid}:
raise ValueError(f"Browser trace request ID mismatch: {trace_path}")
total = difference(marks, "runClick", "indexedDbCommittedPointer")
waterfall = []
for (left, left_name), (right, right_name) in zip(AXIS, AXIS[1:]):
value = difference(marks, left, right)
metric = f"{left_name}_to_{right_name}"
entry = {"metric": metric, "fromMark": left, "toMark": right,
"startMs": marks.get(left), "endMs": marks.get(right), "durationMs": value,
"percentOfClickToCommit": ratio(value, total), "negative": value is not None and value < 0}
waterfall.append(entry)
self.observe(run, "frontend_waterfall", metric, value, parent="click_to_commit",
denominator=total, source=str(trace_path.relative_to(self.root)), inclusion=DEFINITIONS["waterfall"])
complete = all(number(part["durationMs"]) for part in waterfall)
if complete and not math.isclose(sum(p["durationMs"] for p in waterfall), total, abs_tol=1e-6):
raise ValueError(f"Waterfall does not telescope for {sid}")
run["frontend"] = {"timeOrigin": trace["timeOrigin"], "marks": marks,
"waterfall": waterfall, "clickToCommitMs": total, "waterfallComplete": complete,
"negativeIntervals": [part["metric"] for part in waterfall if part["negative"]]}
for key, value in original.items():
if key in ("run", "timeOrigin") or isinstance(value, bool):
continue
if number(value) or value is None:
unit = "ms" if key.endswith("Ms") else "bytes" if key.endswith("Bytes") else "count" if key.endswith("Count") else "number"
self.observe(run, "frontend_metrics", key, value, unit, source=str(source.relative_to(self.root)))
native = original.get("native", {})
for key, value in native.items():
if number(value):
unit = "ms" if key.endswith("Seconds") else "simulated_s" if key in ("simulatedUntil", "maxAcceptedStep") else "count"
self.observe(run, "native_reported", key, value * 1000 if key.endswith("Seconds") else value, unit,
source=str(source.relative_to(self.root)), inclusion="original browser native diagnostic; processWallSeconds includes result read")
run["buildCost"] = {"cacheHit": native.get("cacheHit"), "buildKey": native.get("buildKey"),
"reportedSeconds": native.get("buildSeconds"),
"classification": "cache_hit" if native.get("cacheHit") is True else "cold_build" if native.get("cacheHit") is False else "unknown"}
self.observe(run, "build", run["buildCost"]["classification"],
native["buildSeconds"] * 1000 if number(native.get("buildSeconds")) else None,
source=str(source.relative_to(self.root)), inclusion="warmups separate; cacheHit determines cold/cache classification")
backend_path = self.root / "backend-profiled/requests" / sid / "stages.json"
if mode == "profiled" and backend_path.exists():
backend_data = self.read(backend_path)
run["backend"] = self.backend(run, backend_data, str(backend_path.relative_to(self.root)))
for key in ("buildKey", "nfev", "acceptedSteps", "solveSeconds"):
if backend_data.get("native", {}).get(key) != native.get(key):
raise ValueError(f"Browser/backend native diagnostic mismatch for {sid}: {key}")
else:
run["backend"] = None
if mode == "profiled": self.warnings.append(f"{sid}: completed browser row has no backend stages.json yet")
runs.append(run)
measured = sum(r["phase"] == "measured" for r in runs)
if measured != expected_runs:
self.warnings.append(f"{mode}: {measured} measured run(s), expected {expected_runs}")
if summary.get("errors"):
self.warnings.append(f"{mode}: browser summary contains errors; inspect source before interpreting results")
environment = self.root / f"backend-{mode}" / "environment.json"
return {"source": str(source.relative_to(self.root)), "browser": summary.get("browser"),
"node": summary.get("node"), "input": summary.get("input"), "inputSha256": summary.get("inputSha256"),
"buildAssetSetSha256": summary.get("buildAssetSetSha256"), "servedAssets": summary.get("servedAssets"),
"sourceDefinitions": summary.get("definitions"), "initialNavigation": summary.get("initialNavigation"),
"backendEnvironment": self.read(environment) if environment.exists() else None,
"measuredRunCount": measured, "warmupRunCount": len(runs) - measured, "runs": runs}
def aggregate(self) -> list[dict]:
buckets: dict[tuple, list[dict]] = {}
for observation in self.observations:
key = tuple(observation[k] for k in ("group", "phase", "domain", "metric", "unit", "parent"))
buckets.setdefault(key, []).append(observation)
result = []
for key, rows in sorted(buckets.items()):
entry = dict(zip(("group", "phase", "domain", "metric", "unit", "parent"), key))
entry.update(statistics([r["value"] for r in rows]))
entry["percentOfParent"] = statistics([r["percentOfParent"] for r in rows])
entry["runs"] = [{"run": r["run"], "simulationId": r["simulationId"]} for r in rows]
result.append(entry)
return result
def write(self, expected_runs: int) -> dict:
groups = {mode: self.group(mode, expected_runs) for mode in ("control", "profiled")}
if groups["control"]["inputSha256"] != groups["profiled"]["inputSha256"]:
raise ValueError("Control/profiled input SHA mismatch")
if groups["control"]["buildAssetSetSha256"] != groups["profiled"]["buildAssetSetSha256"]:
self.warnings.append("Control/profiled frontend asset sets differ")
aggregates = self.aggregate()
build_costs = [{"group": mode, "run": r["run"], "phase": r["phase"],
"simulationId": r["simulationId"], **r["buildCost"]}
for mode, group in groups.items() for r in group["runs"]]
output = {"schemaVersion": 1, "experimentRoot": str(self.root),
"script": str(Path(__file__).resolve().relative_to(REPO)),
"scriptSha256": hashlib.sha256(Path(__file__).read_bytes()).hexdigest(),
"definitions": DEFINITIONS, "warnings": self.warnings, "sourceFiles": self.sources,
"groups": groups, "observations": self.observations, "aggregates": aggregates,
"complete": not self.warnings, "buildCosts": build_costs,
"warmupBuildCosts": [cost for cost in build_costs if cost["phase"] == "warmup"],
"coldBuildCosts": [cost for cost in build_costs if cost["classification"] == "cold_build"]}
(self.root / "summary.json").write_text(json.dumps(output, ensure_ascii=False, indent=2, allow_nan=False) + "\n")
fields = ["group", "phase", "run", "simulationId", "domain", "metric", "statistic", "value", "unit",
"parent", "denominatorValue", "percentOfParent", "count", "missingCount", "inclusion", "source"]
with (self.root / "timings.csv").open("w", encoding="utf-8", newline="") as stream:
writer = csv.DictWriter(stream, fieldnames=fields)
writer.writeheader()
for row in self.observations:
writer.writerow({**row, "statistic": "run", "count": int(number(row["value"])), "missingCount": int(row["value"] is None)})
for entry in aggregates:
for stat in ("median", "min", "max"):
writer.writerow({**{key: entry[key] for key in ("group", "phase", "domain", "metric", "unit", "parent")},
"statistic": stat, "value": entry[stat], "percentOfParent": entry["percentOfParent"][stat],
"count": entry["count"], "missingCount": entry["missingCount"],
"inclusion": "values and same-run percentages aggregated separately; do not add medians"})
return output
def main() -> None:
parser = argparse.ArgumentParser(description=__doc__)
parser.add_argument("--root", type=Path, default=REPO / "test/web-cost-20260911")
parser.add_argument("--expected-runs", type=int, default=3)
args = parser.parse_args()
if args.expected_runs < 1:
parser.error("--expected-runs must be positive")
summary = Summary(args.root).write(args.expected_runs)
print(json.dumps({"root": summary["experimentRoot"], "complete": summary["complete"],
"runs": {mode: {"measured": value["measuredRunCount"], "warmup": value["warmupRunCount"]}
for mode, value in summary["groups"].items()},
"observations": len(summary["observations"]), "warnings": summary["warnings"]}, ensure_ascii=False, indent=2))
if __name__ == "__main__":
main()