diff --git a/debug-trace/20260920T172648Z-perf-load/perf-load.html b/debug-trace/20260920T172648Z-perf-load/perf-load.html new file mode 100644 index 0000000..778972f --- /dev/null +++ b/debug-trace/20260920T172648Z-perf-load/perf-load.html @@ -0,0 +1,20 @@ + +
API https://api.veraetime.net · wait:true · unique hashes · workers 32
Run 20260920T172648Z · 2026-09-20T17:26:48.886935Z → 2026-09-20T17:27:38.912194Z
JetStream: not used (standing ban on job-complete messages).
+| n | workers | wall s | rps | ok | fail | +min | avg | p50 | p75 | p80 | p90 | p95 | max | +CPU% avg | RSS MB avg | +
|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
| 20 | 20 | 5.37 | 3.7 | 20 | 0 | 5025.6 | 5203.3 | 5210.6 | 5294.6 | 5305.7 | 5334.6 | 5361.5 | 5369.1 | 0.0 | 0.0 |
| 100 | 32 | 1.87 | 53.6 | 100 | 0 | 293.7 | 509.2 | 572.5 | 620.7 | 622.4 | 628.9 | 639.1 | 680.5 | 0.0 | 0.0 |
| 1000 | 32 | 41.96 | 23.8 | 1000 | 0 | 227.9 | 1324.5 | 1442.8 | 1611.2 | 1643.1 | 1695.1 | 1744.0 | 1833.0 | 0.0 | 0.0 |
Latency columns are milliseconds.
+ diff --git a/debug-trace/20260920T172648Z-perf-load/perf-load.json b/debug-trace/20260920T172648Z-perf-load/perf-load.json new file mode 100644 index 0000000..7bd5dac --- /dev/null +++ b/debug-trace/20260920T172648Z-perf-load/perf-load.json @@ -0,0 +1,124 @@ +{ + "run_id": "20260920T172648Z", + "api": "https://api.veraetime.net", + "workers": 32, + "started": "2026-09-20T17:26:48.886935Z", + "ended": "2026-09-20T17:27:38.912194Z", + "jetstream": false, + "batches": [ + { + "n": 20, + "workers": 20, + "wall_s": 5.37278766700183, + "throughput_rps": 3.722462386301704, + "ok": 20, + "fail": 0, + "latency_ms": { + "min": 5025.597832995118, + "avg": 5203.286902100081, + "p50": 5210.553000004438, + "p75": 5294.564542004082, + "p80": 5305.693332993542, + "p90": 5334.555708002881, + "p95": 5361.513374999049, + "max": 5369.099709001603 + }, + "errors": [], + "host": { + "samples": 3, + "proc_cpu_pct": { + "min": null, + "avg": null, + "p50": null, + "p95": null, + "max": null + }, + "proc_rss_mb": { + "min": null, + "avg": null, + "max": null + }, + "host_mem_available_gb": { + "min": null, + "avg": null + } + } + }, + { + "n": 100, + "workers": 32, + "wall_s": 1.8663768750047893, + "throughput_rps": 53.579746587753554, + "ok": 100, + "fail": 0, + "latency_ms": { + "min": 293.70145899883937, + "avg": 509.17000792986073, + "p50": 572.5267500019982, + "p75": 620.7261669987929, + "p80": 622.3660830000881, + "p90": 628.9407919975929, + "p95": 639.146207999147, + "max": 680.5119999989984 + }, + "errors": [], + "host": { + "samples": 1, + "proc_cpu_pct": { + "min": null, + "avg": null, + "p50": null, + "p95": null, + "max": null + }, + "proc_rss_mb": { + "min": null, + "avg": null, + "max": null + }, + "host_mem_available_gb": { + "min": null, + "avg": null + } + } + }, + { + "n": 1000, + "workers": 32, + "wall_s": 41.9622362500013, + "throughput_rps": 23.83095109713008, + "ok": 1000, + "fail": 0, + "latency_ms": { + "min": 227.90712500136578, + "avg": 1324.5385765079918, + "p50": 1442.7641669972218, + "p75": 1611.1604170000646, + "p80": 1643.1413340033032, + "p90": 1695.0884580001002, + "p95": 1743.9547500034678, + "max": 1832.9792500007898 + }, + "errors": [], + "host": { + "samples": 21, + "proc_cpu_pct": { + "min": null, + "avg": null, + "p50": null, + "p95": null, + "max": null + }, + "proc_rss_mb": { + "min": null, + "avg": null, + "max": null + }, + "host_mem_available_gb": { + "min": null, + "avg": null + } + } + } + ] +} diff --git a/debug-trace/20260920T172745Z-perf-load/perf-load.html b/debug-trace/20260920T172745Z-perf-load/perf-load.html new file mode 100644 index 0000000..5fc2454 --- /dev/null +++ b/debug-trace/20260920T172745Z-perf-load/perf-load.html @@ -0,0 +1,20 @@ + +API https://api.veraetime.net · wait:true · unique hashes · workers 64
Run 20260920T172745Z · 2026-09-20T17:27:45.639008Z → 2026-09-20T17:44:37.878331Z
JetStream: not used (standing ban on job-complete messages).
+| n | workers | wall s | rps | ok | fail | +min | avg | p50 | p75 | p80 | p90 | p95 | max | +CPU% avg | RSS MB avg | +
|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
| 10000 | 64 | 1012.14 | 9.9 | 10000 | 0 | 223.6 | 6443.0 | 2564.7 | 11075.0 | 11391.4 | 12406.4 | 14655.4 | 25920.3 | 0.0 | 0.0 |
Latency columns are milliseconds.
+ diff --git a/debug-trace/20260920T172745Z-perf-load/perf-load.json b/debug-trace/20260920T172745Z-perf-load/perf-load.json new file mode 100644 index 0000000..640dbf4 --- /dev/null +++ b/debug-trace/20260920T172745Z-perf-load/perf-load.json @@ -0,0 +1,48 @@ +{ + "run_id": "20260920T172745Z", + "api": "https://api.veraetime.net", + "workers": 64, + "started": "2026-09-20T17:27:45.639008Z", + "ended": "2026-09-20T17:44:37.878331Z", + "jetstream": false, + "batches": [ + { + "n": 10000, + "workers": 64, + "wall_s": 1012.1443300000028, + "throughput_rps": 9.880013851384192, + "ok": 10000, + "fail": 0, + "latency_ms": { + "min": 223.60091700102203, + "avg": 6443.033584746633, + "p50": 2564.6598329985864, + "p75": 11074.983416998293, + "p80": 11391.353541999706, + "p90": 12406.403041997692, + "p95": 14655.448874997091, + "max": 25920.319874996494 + }, + "errors": [], + "host": { + "samples": 495, + "proc_cpu_pct": { + "min": null, + "avg": null, + "p50": null, + "p95": null, + "max": null + }, + "proc_rss_mb": { + "min": null, + "avg": null, + "max": null + }, + "host_mem_available_gb": { + "min": null, + "avg": null + } + } + } + ] +} diff --git a/scripts/perf_stamp_load.py b/scripts/perf_stamp_load.py new file mode 100644 index 0000000..2517504 --- /dev/null +++ b/scripts/perf_stamp_load.py @@ -0,0 +1,296 @@ +#!/usr/bin/env python3 +"""Latency/load stamps against api.veraetime.net with host CPU/RSS samples.""" + +from __future__ import annotations + +import hashlib +import json +import os +import statistics +import subprocess +import threading +import time +import urllib.error +import urllib.request +from concurrent.futures import ThreadPoolExecutor, as_completed +from datetime import datetime, timezone +from pathlib import Path + +ROOT = Path(__file__).resolve().parents[1] +API = os.environ.get("VERAE_GLOBAL_URL", "https://api.veraetime.net") +SIZES = [20, 100, 1000, 10000, 100000] +WORKERS = int(os.environ.get("VERAE_PERF_WORKERS", "32")) + + +def utc() -> str: + return datetime.now(timezone.utc).strftime("%Y-%m-%dT%H:%M:%S.%fZ") + + +def load_token() -> str: + path = Path.home() / ".verae" / "auth.properties" + props: dict[str, str] = {} + for line in path.read_text().splitlines(): + if "=" in line and not line.strip().startswith("#"): + k, v = line.split("=", 1) + props[k.strip()] = v.strip() + return os.environ.get("VERAE_GLOBAL_TOKEN") or props.get("access_token") or props.get("auth_token") or "" + + +def pct(xs: list[float], p: float) -> float | None: + if not xs: + return None + s = sorted(xs) + i = min(len(s) - 1, max(0, int(round((p / 100.0) * (len(s) - 1))))) + return s[i] + + +def stamp_one(token: str, digest: str, timeout: float = 60.0) -> dict: + body = json.dumps( + { + "data": digest, + "digest": digest, + "hashAlg": "SHA256", + "restamp": False, + "wait": True, + } + ).encode() + req = urllib.request.Request( + API + "/api/timestamp", + data=body, + method="POST", + headers={ + "Content-Type": "application/json", + "Authorization": f"Bearer {token}", + }, + ) + t0 = time.perf_counter() + try: + with urllib.request.urlopen(req, timeout=timeout) as resp: + raw = resp.read() + ms = (time.perf_counter() - t0) * 1000 + parsed = json.loads(raw) if raw else {} + return { + "ok": True, + "status": resp.status, + "ms": ms, + "jobId": parsed.get("jobId"), + "certificate": parsed.get("certificate"), + } + except urllib.error.HTTPError as e: + ms = (time.perf_counter() - t0) * 1000 + return {"ok": False, "status": e.code, "ms": ms, "error": e.read()[:200].decode("utf-8", "replace")} + except Exception as e: + ms = (time.perf_counter() - t0) * 1000 + return {"ok": False, "status": 0, "ms": ms, "error": f"{type(e).__name__}: {e}"} + + +def sample_host(stop: threading.Event, samples: list[dict]) -> None: + while not stop.is_set(): + try: + out = subprocess.check_output( + [ + "ssh", + "-o", + "BatchMode=yes", + "ns1", + "pid=$(pgrep -n -f 'timestamping-service/main -config' || true); " + "if [ -n \"$pid\" ]; then ps -p \"$pid\" -o %cpu=,rss=; " + "else echo NA NA; fi; " + "awk '/^cpu /{u=$2+$4; t=$2+$3+$4+$5; print u,t}' /proc/stat; " + "awk '/MemAvailable:/{print $2}' /proc/meminfo", + ], + text=True, + timeout=8, + ) + lines = [ln.strip() for ln in out.splitlines() if ln.strip()] + cpu_p, rss = (None, None) + host_u = host_t = None + mem_avail = None + if len(lines) >= 1 and lines[0] != "NA NA": + parts = lines[0].split() + if len(parts) >= 2: + cpu_p, rss = float(parts[0]), int(parts[1]) + if len(lines) >= 2: + u, t = lines[1].split()[:2] + host_u, host_t = int(u), int(t) + if len(lines) >= 3: + mem_avail = int(lines[2]) + samples.append( + { + "at": utc(), + "proc_cpu_pct": cpu_p, + "proc_rss_kb": rss, + "host_cpu_jiffies_used": host_u, + "host_cpu_jiffies_total": host_t, + "mem_available_kb": mem_avail, + } + ) + except Exception as e: + samples.append({"at": utc(), "error": str(e)}) + stop.wait(1.0) + + +def run_size(token: str, n: int, workers: int, run_id: str) -> dict: + stop = threading.Event() + samples: list[dict] = [] + mon = threading.Thread(target=sample_host, args=(stop, samples), daemon=True) + mon.start() + t0 = time.perf_counter() + results = [] + with ThreadPoolExecutor(max_workers=workers) as pool: + futs = [] + for i in range(n): + digest = hashlib.sha256(f"Verae-Perf-{run_id}-{i}".encode()).hexdigest() + futs.append(pool.submit(stamp_one, token, digest)) + for fut in as_completed(futs): + results.append(fut.result()) + wall_s = time.perf_counter() - t0 + stop.set() + mon.join(timeout=3) + lat = [r["ms"] for r in results] + oks = [r for r in results if r.get("ok")] + return { + "n": n, + "workers": workers, + "wall_s": wall_s, + "throughput_rps": n / wall_s if wall_s else None, + "ok": len(oks), + "fail": n - len(oks), + "latency_ms": { + "min": min(lat) if lat else None, + "avg": statistics.fmean(lat) if lat else None, + "p50": pct(lat, 50), + "p75": pct(lat, 75), + "p80": pct(lat, 80), + "p90": pct(lat, 90), + "p95": pct(lat, 95), + "max": max(lat) if lat else None, + }, + "host_samples": samples, + "errors": [r for r in results if not r.get("ok")][:20], + } + + +def host_summary(samples: list[dict]) -> dict: + cpus = [s["proc_cpu_pct"] for s in samples if isinstance(s.get("proc_cpu_pct"), (int, float))] + rss = [s["proc_rss_kb"] for s in samples if isinstance(s.get("proc_rss_kb"), int)] + avail = [s["mem_available_kb"] for s in samples if isinstance(s.get("mem_available_kb"), int)] + return { + "samples": len(samples), + "proc_cpu_pct": { + "min": min(cpus) if cpus else None, + "avg": statistics.fmean(cpus) if cpus else None, + "p50": pct(cpus, 50), + "p95": pct(cpus, 95), + "max": max(cpus) if cpus else None, + }, + "proc_rss_mb": { + "min": (min(rss) / 1024) if rss else None, + "avg": (statistics.fmean(rss) / 1024) if rss else None, + "max": (max(rss) / 1024) if rss else None, + }, + "host_mem_available_gb": { + "min": (min(avail) / 1e6) if avail else None, + "avg": (statistics.fmean(avail) / 1e6) if avail else None, + }, + } + + +def html_report(data: dict) -> str: + rows = [] + for b in data["batches"]: + L = b["latency_ms"] + H = b["host"] + rows.append( + "API {html_esc(data['api'])} · wait:true · unique hashes · workers {data['workers']}
Run {html_esc(data['run_id'])} · {html_esc(data['started'])} → {html_esc(data['ended'])}
JetStream: not used (standing ban on job-complete messages).
+| n | workers | wall s | rps | ok | fail | +min | avg | p50 | p75 | p80 | p90 | p95 | max | +CPU% avg | RSS MB avg | +
|---|
Latency columns are milliseconds.
+ +""" + + +def html_esc(s) -> str: + return ( + str(s) + .replace("&", "&") + .replace("<", "<") + .replace(">", ">") + .replace('"', """) + ) + + +def main() -> int: + token = load_token() + if not token: + raise SystemExit("no VERAE_GLOBAL_TOKEN / ~/.verae/auth.properties") + run_id = datetime.now(timezone.utc).strftime("%Y%m%dT%H%M%SZ") + dest = ROOT / "debug-trace" / f"{run_id}-perf-load" + dest.mkdir(parents=True, exist_ok=True) + started = utc() + batches = [] + sizes = [int(x) for x in os.environ.get("VERAE_PERF_SIZES", ",".join(map(str, SIZES))).split(",") if x] + for n in sizes: + workers = min(WORKERS, n) + print(f"=== n={n} workers={workers} ===", flush=True) + batch = run_size(token, n, workers, run_id) + batch["host"] = host_summary(batch.pop("host_samples")) + print(json.dumps({k: batch[k] for k in ("n", "ok", "fail", "wall_s", "throughput_rps", "latency_ms")}, indent=2), flush=True) + batches.append(batch) + ended = utc() + data = { + "run_id": run_id, + "api": API, + "workers": WORKERS, + "started": started, + "ended": ended, + "jetstream": False, + "batches": batches, + } + (dest / "perf-load.json").write_text(json.dumps(data, indent=2) + "\n") + (dest / "perf-load.html").write_text(html_report(data)) + print("wrote", dest / "perf-load.html") + return 0 + + +if __name__ == "__main__": + raise SystemExit(main())