From 0bbeb7cd86f4400b0c1c807517ec6dfff5b56084 Mon Sep 17 00:00:00 2001 From: Austin Harris Date: Sun, 27 Sep 2026 16:02:39 -0600 Subject: [PATCH 1/4] AUS-1011: Add a CPU-utilisation axis and a Hugging Face Jobs runner to the harness Every timed benchmark row now reports CPU during its window as a percent of the cores available to the process: the whole machine (cgroup counters inside a container, /proc/stat or GetSystemTimes otherwise), the harness process, and the dedicated TCP client threads. The figures trail every table row and sweep cell line and go into the sweep JSON as per-series arrays that render.py folds into the explorer tables; the five committed runs stay valid without them. The machine description is derived at run time (with the cgroup quota when one applies) and can be overridden with JSONRPC_BENCH_MACHINE; a --machine mode prints it alone. benchmarks/hf/ holds the Hugging Face Jobs runner: run.sh for the .NET 10 SDK image, launch.sh for the hf jobs run line, fetch.py to pull the framed sweep files out of the job log. --- CHANGELOG.md | 2 + README.md | 10 +- TestServer_Console/AsyncBenchmark.cs | 52 ++++--- TestServer_Console/Benchmark.cs | 19 ++- TestServer_Console/CompareBenchmark.cs | 58 +++++--- TestServer_Console/CpuMeter.cs | 177 +++++++++++++++++++++++ TestServer_Console/GrpcCompare.cs | 10 +- TestServer_Console/KestrelBenchmark.cs | 41 +++--- TestServer_Console/PrintHardware.cs | 51 ++++++- TestServer_Console/Program.cs | 20 ++- benchmarks/charts/explorer.html | 7 +- benchmarks/charts/explorer_template.html | 7 +- benchmarks/charts/render.py | 18 +++ benchmarks/charts/test_render.py | 27 ++++ benchmarks/hf/fetch.py | 51 +++++++ benchmarks/hf/launch.sh | 18 +++ benchmarks/hf/run.sh | 52 +++++++ 17 files changed, 532 insertions(+), 88 deletions(-) create mode 100644 TestServer_Console/CpuMeter.cs create mode 100644 benchmarks/hf/fetch.py create mode 100644 benchmarks/hf/launch.sh create mode 100644 benchmarks/hf/run.sh diff --git a/CHANGELOG.md b/CHANGELOG.md index f36070f..43c3c48 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -12,6 +12,8 @@ behaviour: a breaking change to either means a new major version. ### Added +- Every benchmark row reports CPU during its timed window (machine, harness process, client threads) as a percent of the available cores; the sweep JSON, the explorer tables and a Hugging Face Jobs runner (`benchmarks/hf/`) carry it. + - `JsonRpcLimits` and `Config.SetLimits`: the core rejects documents over 4 MiB and batches over 1024 entries with `-32600` and a `data` object naming the limit; `JsonRpcLimits.Unlimited` restores the 1.x behaviour. - `ServiceBinder.BindInterface` registers interface trees atomically, with contract naming, filtering, defaults and ownership-aware disposal (`RpcBinding`). - `ServiceBinder.BindMethod` registers any delegate as a method without attributes or a service class. diff --git a/README.md b/README.md index 424b3cf..91f890a 100644 --- a/README.md +++ b/README.md @@ -630,6 +630,8 @@ dotnet run --project samples/WasmHost # browser: " The three modes measure different things and are named for the entry point they call. `Process(bytes), dedicated threads` measures the library alone. `ProcessAsync(bytes), awaited workers` measures the entry point an asynchronous host calls. `Legacy Process(string), scheduled synchronous work` measures the 1.x string overloads through the thread pool. The Kestrel rows say whether `EnableAsyncMethods` was on. +On Hugging Face Jobs, run `benchmarks/hf/launch.sh [runs]` and retrieve JSON with `benchmarks/hf/fetch.py `; `cpu-upgrade` is 8 vCPU ($0.03/h), `cpu-xl` is 16 vCPU ($1/h), and `cpu-performance` is 32 vCPU ($1.90/h), while `cpu-basic` is 2 vCPU for smoke runs only. These are shared vCPUs, so each job's figures belong to its own machine row and are never merged into the reference-box tables. + ### Sync: the library alone `--sync` calls the byte-level `JsonRpcProcessor.Process` in a loop from 1, 2, 4, ... threads up to the core count, so it measures parsing, dispatch, binding and response writing with no scheduler in the way. @@ -694,7 +696,7 @@ This mode is slower than the byte modes because it measures the cost of the .NET ### Kestrel: through the AspNetCore package -`--kestrel [seconds]` starts a real Kestrel on loopback with `MapJsonRpc` and `JsonRpcConnectionHandler`, then drives it with 16 clients on the same machine. Every figure is therefore an upper bound for one box talking to itself. The in-process rows show the same requests through the byte entry point with no transport, to give a sense of scale. The `EnableAsyncMethods = false` rows are the default, where the host calls `Process`. `--kestrel 3 async` runs the same host with `EnableAsyncMethods = true` and sends every document through `ProcessAsync`. It also adds a TCP row whose five methods await `Task.Yield()` before answering. +`--kestrel [seconds]` starts a real Kestrel on loopback with `MapJsonRpc` and `JsonRpcConnectionHandler`, then drives it with 16 clients on the same machine. Every figure is therefore an upper bound for one box talking to itself. The in-process rows show the same requests through the byte entry point with no transport, to give a sense of scale. The `EnableAsyncMethods = false` rows are the default, where the host calls `Process`. `--kestrel 3 async` runs the same host with `EnableAsyncMethods = true` and sends every document through `ProcessAsync`. It also adds a TCP row whose five methods await `Task.Yield()` before answering. The trailing text on each `--kestrel` row reports system, harness-process and, for TCP, dedicated-client CPU during that row's timed window as a share of the available cores. @@ -714,7 +716,7 @@ The TCP client keeps 256 requests in flight per connection and refills from a pr ### Versus StreamJsonRpc and gRPC -[StreamJsonRpc](https://www.nuget.org/packages/StreamJsonRpc) is Microsoft's JSON-RPC library, the one behind Visual Studio and the language-server stack. `--compare` hosts both libraries on the same Kestrel TCP listener and drives them with the same pipelining client (16 connections, 256 requests in flight each), so the only variable is the library answering. StreamJsonRpc requires the `jsonrpc` member, so every request in this mode carries `"jsonrpc":"2.0"`, which is why the JSON-RPC.Net rows are a little below the other tables. The same mode also hosts [gRPC for .NET](https://learn.microsoft.com/aspnet/core/grpc/) (HTTP/2, protobuf) on the same Kestrel, answering the same five calls from [calculator.proto](TestServer_Console/Protos/calculator.proto), driven by its own client with the same shape: 16 channels, 256 calls in flight each. Each row was run twice for 3 s; both results are shown. +[StreamJsonRpc](https://www.nuget.org/packages/StreamJsonRpc) is Microsoft's JSON-RPC library, the one behind Visual Studio and the language-server stack. `--compare` hosts both libraries on the same Kestrel TCP listener and drives them with the same pipelining client (16 connections, 256 requests in flight each), so the only variable is the library answering. StreamJsonRpc requires the `jsonrpc` member, so every request in this mode carries `"jsonrpc":"2.0"`, which is why the JSON-RPC.Net rows are a little below the other tables. The same mode also hosts [gRPC for .NET](https://learn.microsoft.com/aspnet/core/grpc/) (HTTP/2, protobuf) on the same Kestrel, answering the same five calls from [calculator.proto](TestServer_Console/Protos/calculator.proto), driven by its own client with the same shape: 16 channels, 256 calls in flight each. Each row was run twice for 3 s; both results are shown. The trailing text on each `--compare` row reports system, harness-process and, for TCP, dedicated-client CPU during that row's timed window as a share of the available cores. @@ -757,7 +759,7 @@ StreamJsonRpc's server side has no "document in, document out" call, so its in-p Every library and transport by client connections, 1 to 16: three panels on a shared log axis, one per library, with a marker shape and dash per setting and whiskers spanning five runs -`--sweep` runs every one of those paths at 1, 2, 4, 8 and 16 client connections (gRPC: channels) and writes one JSON file per run; the chart above is five 2 s runs per point, the marker at the median and the whisker from the lowest to the highest run. It is a separate session from the tables: the WSL virtual machine was running and other work was active, so its absolute figures sit below the table rows (JSON-RPC.Net over TCP 10.9 M to 13.0 M at 16 connections against 13.7 M to 14.6 M in the table), and its gRPC unary figure runs higher (360 k to 404 k against 192 k to 198 k; the cause is not pinned down, and the table keeps the `--compare` figure). What the sweep adds is the shape: JSON-RPC.Net over TCP and batched HTTP climb almost linearly with connections, StreamJsonRpc gains 8 to 10× from one connection to sixteen, and gRPC's .NET client is flat from two channels on because it competes with the server for the same eight cores. +`--sweep` runs every one of those paths at 1, 2, 4, 8 and 16 client connections (gRPC: channels) and writes one JSON file per run; the chart above is five 2 s runs per point, the marker at the median and the whisker from the lowest to the highest run. New sweep files also record the available core count and per-cell system, process and dedicated TCP-client CPU percentages; a high client share can mean the harness is competing with the server for CPU. It is a separate session from the tables: the WSL virtual machine was running and other work was active, so its absolute figures sit below the table rows (JSON-RPC.Net over TCP 10.9 M to 13.0 M at 16 connections against 13.7 M to 14.6 M in the table), and its gRPC unary figure runs higher (360 k to 404 k against 192 k to 198 k; the cause is not pinned down, and the table keeps the `--compare` figure). What the sweep adds is the shape: JSON-RPC.Net over TCP and batched HTTP climb almost linearly with connections, StreamJsonRpc gains 8 to 10× from one connection to sixteen, and gRPC's .NET client is flat from two channels on because it competes with the server for the same eight cores. The [benchmark explorer](https://astn.github.io/JSON-RPC.NET/benchmarks/charts/explorer.html) is the same data as an interactive page: toggle series, hover or tab to a point for the exact low, median, high and every run, switch the axis between log and linear, and download the data. It is one self-contained HTML file, [benchmarks/charts/explorer.html](benchmarks/charts/explorer.html), so it also works saved to disk. @@ -812,7 +814,7 @@ The 1.x projects that 2.0 does not build (`AustinHarris.JsonRpc.Client`, `Austin ### Charts -The charts, the explorer page and the benchmark figures in this README come from one data file, [benchmarks/charts/benchmarks.json](benchmarks/charts/benchmarks.json): the tables transcribed with their published precision and conditions, plus the `--sweep` run files. `python benchmarks/charts/render.py` (plain Python, no packages) renders every chart in a light and a dark variant, which the README picks between with a `` element, and `render.py --check` fails if a committed chart is stale or a figure in this README no longer matches the data; the pull-request build runs it. GitHub serves README images through a proxy as plain ``, so the SVGs carry no scripts, hover text or links, and every range is drawn as an interval with its figures beside it; the interactive parts live on the explorer page. +The charts, the explorer page and the benchmark figures in this README come from one data file, [benchmarks/charts/benchmarks.json](benchmarks/charts/benchmarks.json): the tables transcribed with their published precision and conditions, plus the `--sweep` run files. `python benchmarks/charts/render.py` (plain Python, no packages) renders every chart in a light and a dark variant, which the README picks between with a `` element, and `render.py --check` fails if a committed chart is stale or a figure in this README no longer matches the data; the pull-request build runs it. GitHub serves README images through a proxy as plain ``, so the SVGs carry no scripts, hover text or links, and every range is drawn as an interval with its figures beside it; the interactive parts live on the explorer page. The explorer tables show median system, process and dedicated TCP-client CPU percentages when the sweep files contain them; a high client share can limit the requests the harness feeds to the server. ## License diff --git a/TestServer_Console/AsyncBenchmark.cs b/TestServer_Console/AsyncBenchmark.cs index b451674..d141dcd 100644 --- a/TestServer_Console/AsyncBenchmark.cs +++ b/TestServer_Console/AsyncBenchmark.cs @@ -37,7 +37,7 @@ internal static readonly (string shape, RpcContextFlow flow)[] Rows = /// The rows the per-serializer diagnostics after the gate measure: the inline None rows and the yieldsOnce None row. internal static readonly (string shape, RpcContextFlow flow)[] DiagnosticRows = InlineRows.Append(("yield", RpcContextFlow.None)).ToArray(); - internal readonly record struct Measurement(long Count, double Seconds, double StartupSeconds, long AllocatedBytes) + internal readonly record struct Measurement(long Count, double Seconds, double StartupSeconds, long AllocatedBytes, CpuUsage Cpu) { public double RpcPerSec => Count / Seconds; public double BytesPerRpc => Count == 0 ? 0 : AllocatedBytes / (double)Count; @@ -59,8 +59,8 @@ internal static async Task RunAsync(Action print, double seconds, int wo var m = await Measure(session, rowInputs, workers, seconds, processWide: yield); string label = yield ? "one request (yieldsOnce)" : "equal-weight mix of five requests"; print($"{shape} / {flow}: {m.Count:N0} RPCs, {workers} workers, {m.Seconds:F3} s, {m.RpcPerSec:N0} RPC/s; worker startup {m.StartupSeconds * 1000:F1} ms; " + - $"{(yield ? "process-wide" : "worker-thread")} allocation total {m.AllocatedBytes:N0} B ({m.BytesPerRpc:F0} B/RPC, including method and harness allocations); {label}."); - summary.Add(new BenchmarkRunner.ChartRow($"{shape} / {flow}", m.RpcPerSec, $"{m.Count,12:N0} RPCs {m.BytesPerRpc,6:F0} B/RPC")); + $"{(yield ? "process-wide" : "worker-thread")} allocation total {m.AllocatedBytes:N0} B ({m.BytesPerRpc:F0} B/RPC, including method and harness allocations); {label}; {m.Cpu.TrailingText}."); + summary.Add(new BenchmarkRunner.ChartRow($"{shape} / {flow}", m.RpcPerSec, $"{m.Count,12:N0} RPCs {m.BytesPerRpc,6:F0} B/RPC {m.Cpu.TrailingText}")); } finally { Handler.DestroySession(session); } } @@ -78,7 +78,7 @@ internal static async Task ScaleAsync(Action print, double seconds if (workers < 2) throw new ArgumentOutOfRangeException(nameof(workers)); var counts = new[] { 1, 2, workers }.Distinct().ToArray(); print($"Scaling check: ProcessAsync(bytes), {string.Join(", ", counts)} workers, {runs} paired runs of {seconds:0.#} s per cell, medians; {Environment.ProcessorCount} logical processors; gate {workers}/1 >= {threshold:0.0#}.\n"); - var results = new Dictionary<(string, RpcContextFlow, int), List>(); + var results = new Dictionary<(string, RpcContextFlow, int), List>(); foreach (var (shape, flow) in InlineRows) { string session = "async-scale-" + shape + "-" + flow; @@ -92,9 +92,9 @@ internal static async Task ScaleAsync(Action print, double seconds foreach (int w in counts) { var m = await Measure(session, rowInputs, w, seconds); - print($" run {run}: {shape} / {flow}, {w,2} workers: {m.RpcPerSec,14:N0} RPC/s ({m.Count:N0} RPCs in {m.Seconds:F3} s, startup {m.StartupSeconds * 1000:F1} ms)"); - if (!results.TryGetValue((shape, flow, w), out var list)) results[(shape, flow, w)] = list = new List(); - list.Add(m.RpcPerSec); + print($" run {run}: {shape} / {flow}, {w,2} workers: {m.RpcPerSec,14:N0} RPC/s ({m.Count:N0} RPCs in {m.Seconds:F3} s, startup {m.StartupSeconds * 1000:F1} ms); {m.Cpu.TrailingText}"); + if (!results.TryGetValue((shape, flow, w), out var list)) results[(shape, flow, w)] = list = new List(); + list.Add(m); } } finally { Handler.DestroySession(session); } @@ -102,16 +102,17 @@ internal static async Task ScaleAsync(Action print, double seconds bool pass = true; print(""); - print($"| Registration | 1 worker | 2 workers | {workers} workers | 2/1 | {workers}/1 | gate |"); - print("| --- | ---: | ---: | ---: | ---: | ---: | --- |"); + print($"| Registration | 1 worker | 2 workers | {workers} workers | 2/1 | {workers}/1 | gate | CPU at {workers} workers |"); + print("| --- | ---: | ---: | ---: | ---: | ---: | --- | --- |"); foreach (var (shape, flow) in InlineRows) { - double one = Median(results[(shape, flow, 1)]); - double two = Median(results[(shape, flow, 2)]); - double many = Median(results[(shape, flow, workers)]); + double one = Median(results[(shape, flow, 1)].Select(m => m.RpcPerSec).ToList()); + double two = Median(results[(shape, flow, 2)].Select(m => m.RpcPerSec).ToList()); + double many = Median(results[(shape, flow, workers)].Select(m => m.RpcPerSec).ToList()); + var cpu = MedianCpu(results[(shape, flow, workers)]); bool ok = many / one >= threshold; pass &= ok; - print($"| {shape} / {flow} | {one:N0} | {two:N0} | {many:N0} | {two / one:F2} | {many / one:F2} | {(ok ? "pass" : "FAIL")} |"); + print($"| {shape} / {flow} | {one:N0} | {two:N0} | {many:N0} | {two / one:F2} | {many / one:F2} | {(ok ? "pass" : "FAIL")} | {cpu.TrailingText} |"); } print(""); print(pass ? $"Scaling check passed: every inline row scales at least {threshold:0.0#}x from 1 to {workers} workers." @@ -146,7 +147,7 @@ internal static async Task ScaleDiagnosticsAsync(Action print, double se where = $"serializer {k + 1} of {serializers.Length}"; Config.SetSerializer(serializers[k]()); string name = Config.Serializer.Name; - rows.Add($"| **{name}** | | | | |"); + rows.Add($"| **{name}** | | | | | |"); foreach (var (shape, flow) in DiagnosticRows) { where = $"{name} / {shape} / {flow}"; @@ -159,10 +160,10 @@ internal static async Task ScaleDiagnosticsAsync(Action print, double se bool yield = shape == "yield"; await Measure(session, rowInputs, workers, Math.Min(seconds, 0.5), processWide: yield); // warm-up var one = await Measure(session, rowInputs, 1, seconds, processWide: yield); - print($" {where}, {1,2} workers: {one.RpcPerSec,14:N0} RPC/s ({one.Count:N0} RPCs in {one.Seconds:F3} s, {one.BytesPerRpc:F0} B/RPC)"); + print($" {where}, {1,2} workers: {one.RpcPerSec,14:N0} RPC/s ({one.Count:N0} RPCs in {one.Seconds:F3} s, {one.BytesPerRpc:F0} B/RPC); {one.Cpu.TrailingText}"); var many = await Measure(session, rowInputs, workers, seconds, processWide: yield); - print($" {where}, {workers,2} workers: {many.RpcPerSec,14:N0} RPC/s ({many.Count:N0} RPCs in {many.Seconds:F3} s)"); - rows.Add($"| {shape} / {flow} | {one.RpcPerSec:N0} | {many.RpcPerSec:N0} | {many.RpcPerSec / one.RpcPerSec:F2} | {one.BytesPerRpc:F0} |"); + print($" {where}, {workers,2} workers: {many.RpcPerSec,14:N0} RPC/s ({many.Count:N0} RPCs in {many.Seconds:F3} s); {many.Cpu.TrailingText}"); + rows.Add($"| {shape} / {flow} | {one.RpcPerSec:N0} | {many.RpcPerSec:N0} | {many.RpcPerSec / one.RpcPerSec:F2} | {one.BytesPerRpc:F0} | {many.Cpu.TrailingText} |"); } finally { Handler.DestroySession(session); } } @@ -172,8 +173,8 @@ internal static async Task ScaleDiagnosticsAsync(Action print, double se finally { Config.SetSerializer(previous); } print(""); - print($"| Serializer / registration | 1 worker | {workers} workers | {workers}/1 | B per request |"); - print("| --- | ---: | ---: | ---: | ---: |"); + print($"| Serializer / registration | 1 worker | {workers} workers | {workers}/1 | B per request | CPU at {workers} workers |"); + print("| --- | ---: | ---: | ---: | ---: | --- |"); foreach (var row in rows) print(row); print(""); if (failure != null) @@ -187,6 +188,16 @@ private static double Median(List values) return n % 2 == 1 ? sorted[n / 2] : (sorted[n / 2 - 1] + sorted[n / 2]) / 2; } + private static CpuUsage MedianCpu(List values) + { + double? Mid(Func select) + { + var measured = values.Select(select).Where(v => v.HasValue).Select(v => v.Value).ToList(); + return measured.Count == 0 ? null : Median(measured); + } + return new CpuUsage(Mid(m => m.Cpu.SystemPercent), Mid(m => m.Cpu.ProcessPercent), null, values[0].Cpu.Cores); + } + private static ReadOnlyMemory[] Inputs(string shape) => shape == "yield" ? new[] { (ReadOnlyMemory)Encoding.UTF8.GetBytes("{\"method\":\"yieldsOnce\",\"id\":6}") } : BenchmarkRunner.taskInputs.Select(t => (ReadOnlyMemory)Encoding.UTF8.GetBytes(t)).ToArray(); @@ -258,6 +269,7 @@ internal static async Task Measure(string session, ReadOnlyMemory Measure(string session, ReadOnlyMemory print = null, JsonRpcSerialize } // warm up: JIT, type plans, compiled invokers - RunSync(session, inputs, serializer, Math.Min(threads, 2), 0.5, out _); + RunSync(session, inputs, serializer, Math.Min(threads, 2), 0.5); // allocation profile per request shape (a zero here means the request never touches the GC) { @@ -90,11 +90,11 @@ internal static void BenchmarkSync(Action print = null, JsonRpcSerialize foreach (var t in threadCounts) { - var elapsed = RunSync(session, inputs, serializer, t, seconds, out long total); + var (total, elapsed, cpu) = RunSync(session, inputs, serializer, t, seconds); double rps = total / elapsed; double mbIn = rps * bytesIn / inputs.Length / (1024.0 * 1024.0); double mbOut = rps * bytesOut / inputs.Length / (1024.0 * 1024.0); - rows.Add(new ChartRow($"{t} thread{(t == 1 ? "" : "s")}", rps, $"{1e9 / rps * t:N0} ns/RPC per thread")); + rows.Add(new ChartRow($"{t} thread{(t == 1 ? "" : "s")}", rps, $"{1e9 / rps * t:N0} ns/RPC per thread {cpu.TrailingText}")); // The detailed boxes are only printed for the two documented points: one thread and all threads. if (t != 1 && t != threads) continue; @@ -121,7 +121,7 @@ internal static void BenchmarkSync(Action print = null, JsonRpcSerialize PrintBarChart($"Sync benchmark - {serializer.Name} - RPC/s by thread count", "Threads", rows); } - internal static double RunSync(string session, ReadOnlyMemory[] inputs, JsonRpcSerializer serializer, int threads, double seconds, out long total) + internal static (long count, double seconds, CpuUsage cpu) RunSync(string session, ReadOnlyMemory[] inputs, JsonRpcSerializer serializer, int threads, double seconds) { var counts = new long[threads * 16]; // padded to avoid false sharing var stop = false; @@ -148,14 +148,15 @@ internal static double RunSync(string session, ReadOnlyMemory[] inputs, Js workers[t].Start(); } ready.SignalAndWait(); + var meter = CpuMeter.Start(); var sw = Stopwatch.StartNew(); Thread.Sleep(TimeSpan.FromSeconds(seconds)); Volatile.Write(ref stop, true); foreach (var w in workers) w.Join(); sw.Stop(); - total = 0; + long total = 0; for (int t = 0; t < threads; t++) total += counts[t * 16]; - return sw.Elapsed.TotalSeconds; + return (total, sw.Elapsed.TotalSeconds, meter.Stop()); } internal static void Benchmark(Action print = null) @@ -193,6 +194,7 @@ internal static void Benchmark(Action print = null) currentPerTaskBytesIn = perTaskBytesIn; currentPerTaskBytesOut = perTaskBytesOut; currentStopwatch = Stopwatch.StartNew(); + var cpuMeter = CpuMeter.Start(); // Live updates every 250 ms. StopProgressTimer() below guarantees no tick is still running here. updateTimer = new System.Threading.Timer(OnProgressTick, null, 250, 250); @@ -205,6 +207,7 @@ internal static void Benchmark(Action print = null) Interlocked.Increment(ref currentBatches); } while (currentStopwatch.Elapsed < minIterationTime); currentStopwatch.Stop(); + var cpu = cpuMeter.Stop(); // Wait for any in-flight tick before printing the final box, then close the iteration under the // lock so a tick that was queued but not yet started sees benchmarkRunning == false and skips. @@ -217,7 +220,7 @@ internal static void Benchmark(Action print = null) double seconds = currentStopwatch.Elapsed.TotalSeconds; long total = (long)cnt * currentBatches; - results.Add(new ChartRow($"#{iteration} {cnt,11:N0}", total / seconds, $"{total,11:N0} RPCs in {seconds:F3} s")); + results.Add(new ChartRow($"#{iteration} {cnt,11:N0}", total / seconds, $"{total,11:N0} RPCs in {seconds:F3} s {cpu.TrailingText}")); } lock (renderLock) @@ -374,4 +377,4 @@ private static void AppendField(StringBuilder sb, string label, string value, st .Append('\n'); } -} \ No newline at end of file +} diff --git a/TestServer_Console/CompareBenchmark.cs b/TestServer_Console/CompareBenchmark.cs index 803eae8..f0cf202 100644 --- a/TestServer_Console/CompareBenchmark.cs +++ b/TestServer_Console/CompareBenchmark.cs @@ -82,19 +82,19 @@ internal static async Task RunAsync(Action print, double seconds = 3, in // ---- in-process floors var memInputs = raw.Select(i => (ReadOnlyMemory)i).ToArray(); - BenchmarkRunner.RunSync(session, memInputs, Config.Serializer, 1, Warm, out _); - var elapsed = BenchmarkRunner.RunSync(session, memInputs, Config.Serializer, 1, seconds, out long total); - rows.Add(new BenchmarkRunner.ChartRow("JSON-RPC.Net in-process, 1 thread", total / elapsed, $"{total,12:N0} RPCs direct call, bytes in, bytes out")); + BenchmarkRunner.RunSync(session, memInputs, Config.Serializer, 1, Warm); + var (total, elapsed, cpu) = BenchmarkRunner.RunSync(session, memInputs, Config.Serializer, 1, seconds); + rows.Add(new BenchmarkRunner.ChartRow("JSON-RPC.Net in-process, 1 thread", total / elapsed, $"{total,12:N0} RPCs direct call, bytes in, bytes out {cpu.TrailingText}")); print($" JSON-RPC.Net in-process done ({rows[^1].RpcPerSec:N0} RPC/s)"); PipeRun(newLine, Warm, pipeline); - var (count, secs) = PipeRun(newLine, seconds, pipeline); - rows.Add(new BenchmarkRunner.ChartRow("StreamJsonRpc in-process, 1 client", count / secs, $"{count,12:N0} RPCs Pipe pair, newline framing, STJ formatter, {pipeline} pipelined")); + var (count, secs, usage) = PipeRun(newLine, seconds, pipeline); + rows.Add(new BenchmarkRunner.ChartRow("StreamJsonRpc in-process, 1 client", count / secs, $"{count,12:N0} RPCs Pipe pair, newline framing, STJ formatter, {pipeline} pipelined {usage.TrailingText}")); print($" StreamJsonRpc in-process done ({count / secs:N0} RPC/s)"); - (count, secs) = await ProxyRun(Warm); - (count, secs) = await ProxyRun(seconds); - rows.Add(new BenchmarkRunner.ChartRow("StreamJsonRpc proxy, sequential await", count / secs, $"{count,12:N0} RPCs {secs / count * 1e6:N1} us per round trip")); + await ProxyRun(Warm); + (count, secs, usage) = await ProxyRun(seconds); + rows.Add(new BenchmarkRunner.ChartRow("StreamJsonRpc proxy, sequential await", count / secs, $"{count,12:N0} RPCs {secs / count * 1e6:N1} us per round trip {usage.TrailingText}")); print($" StreamJsonRpc proxy done ({count / secs:N0} RPC/s)"); // ---- Kestrel TCP, same client for every row @@ -108,20 +108,20 @@ internal static async Task RunAsync(Action print, double seconds = 3, in { Probe(port, inputs, label); KestrelBenchmark.TcpRun(port, inputs, clients, Warm, pipeline, prefix); - (count, secs) = KestrelBenchmark.TcpRun(port, inputs, clients, seconds, pipeline, prefix); - rows.Add(new BenchmarkRunner.ChartRow(label, count / secs, $"{count,12:N0} RPCs")); + (count, secs, usage) = KestrelBenchmark.TcpRun(port, inputs, clients, seconds, pipeline, prefix); + rows.Add(new BenchmarkRunner.ChartRow(label, count / secs, $"{count,12:N0} RPCs {usage.TrailingText}")); print($" {label} done ({count / secs:N0} RPC/s)"); } // ---- gRPC for .NET on the same Kestrel: HTTP/2 + protobuf, one channel per client await GrpcCompare.UnaryRun(grpcPort, clients, pipeline, Warm); - (count, secs) = await GrpcCompare.UnaryRun(grpcPort, clients, pipeline, seconds); - rows.Add(new BenchmarkRunner.ChartRow("gRPC for .NET unary, HTTP/2", count / secs, $"{count,12:N0} RPCs {clients} channels, {pipeline} calls in flight each")); + (count, secs, usage) = await GrpcCompare.UnaryRun(grpcPort, clients, pipeline, seconds); + rows.Add(new BenchmarkRunner.ChartRow("gRPC for .NET unary, HTTP/2", count / secs, $"{count,12:N0} RPCs {clients} channels, {pipeline} calls in flight each {usage.TrailingText}")); print($" gRPC unary done ({count / secs:N0} RPC/s)"); await GrpcCompare.StreamRun(grpcPort, clients, pipeline, Warm); - (count, secs) = await GrpcCompare.StreamRun(grpcPort, clients, pipeline, seconds); - rows.Add(new BenchmarkRunner.ChartRow("gRPC for .NET bidirectional stream", count / secs, $"{count,12:N0} RPCs {clients} streams, {pipeline} calls in flight each")); + (count, secs, usage) = await GrpcCompare.StreamRun(grpcPort, clients, pipeline, seconds); + rows.Add(new BenchmarkRunner.ChartRow("gRPC for .NET bidirectional stream", count / secs, $"{count,12:N0} RPCs {clients} streams, {pipeline} calls in flight each {usage.TrailingText}")); print($" gRPC stream done ({count / secs:N0} RPC/s)"); BenchmarkRunner.PrintBarChart("JSON-RPC.Net vs StreamJsonRpc vs gRPC - RPC/s", "Library / transport", rows); @@ -144,7 +144,7 @@ internal static async Task SweepAsync(Action print, double seconds = 2, await using var h = await StartAsync(pipeline); int[] connections = { 1, 2, 4, 8, 16 }; - (string name, string kind, Func> run)[] series = + (string name, string kind, Func> run)[] series = { ("JSON-RPC.Net, TCP", "ours", (c, s) => Task.FromResult(KestrelBenchmark.TcpRun(h.OursPort, raw, c, s, pipeline, JsonRpcPrefix))), ("JSON-RPC.Net, HTTP, batch of 100 per POST", "ours", (c, s) => KestrelBenchmark.HttpRun(h.HttpUrl, batch, 100, c, s)), @@ -162,14 +162,16 @@ internal static async Task SweepAsync(Action print, double seconds = 2, print($"{Versions()}; Kestrel on loopback, pipeline {pipeline}, {seconds:0.#} s per cell\n"); var results = new double[series.Length, connections.Length]; + var usages = new CpuUsage[series.Length, connections.Length]; for (int ci = 0; ci < connections.Length; ci++) { for (int si = 0; si < series.Length; si++) { await series[si].run(connections[ci], Warm); - var (count, secs) = await series[si].run(connections[ci], seconds); + var (count, secs, cpu) = await series[si].run(connections[ci], seconds); results[si, ci] = count / secs; - print($" {connections[ci],2} connections {series[si].name,-55} {results[si, ci],14:N0} RPC/s"); + usages[si, ci] = cpu; + print($" {connections[ci],2} connections {series[si].name,-55} {results[si, ci],14:N0} RPC/s {cpu.TrailingText}"); } } @@ -182,12 +184,20 @@ internal static async Task SweepAsync(Action print, double seconds = 2, { var doc = new { - machine = "AMD Ryzen 7 7800X3D, 8 cores / 16 threads, Windows 11, .NET 10, Release, Server GC", + machine = MachineDescription.Current(), + cores = Environment.ProcessorCount, date = DateTime.Now.ToString("yyyy-MM-dd"), secondsPerCell = seconds, pipeline, connections, - series = series.Select((s, si) => new { s.name, s.kind, rpcPerSec = connections.Select((_, ci) => Math.Round(results[si, ci])).ToArray() }).ToArray(), + series = series.Select((s, si) => new + { + s.name, s.kind, + rpcPerSec = connections.Select((_, ci) => Math.Round(results[si, ci])).ToArray(), + cpuSystem = connections.Select((_, ci) => usages[si, ci].SystemPercent is double v ? Math.Round(v, 1) : (double?)null).ToArray(), + cpuProcess = connections.Select((_, ci) => usages[si, ci].ProcessPercent is double v ? Math.Round(v, 1) : (double?)null).ToArray(), + cpuClients = connections.Select((_, ci) => usages[si, ci].ClientPercent is double v ? Math.Round(v, 1) : (double?)null).ToArray() + }).ToArray(), }; File.WriteAllText(outputPath, JsonSerializer.Serialize(doc, new JsonSerializerOptions { WriteIndented = true }) + "\n"); print($"\nwrote {outputPath}"); @@ -287,7 +297,7 @@ private static void Probe(int port, byte[][] inputs, string label) /// StreamJsonRpc served over an in-process pair, driven exactly like the TCP client: a ring /// of newline-framed requests, a cursor, and refills whenever the pipeline has room. /// - private static (long count, double seconds) PipeRun(byte[][] inputs, double seconds, int pipeline) + private static (long count, double seconds, CpuUsage cpu) PipeRun(byte[][] inputs, double seconds, int pipeline) { var toServer = new Pipe(); var toClient = new Pipe(); @@ -301,6 +311,7 @@ private static (long count, double seconds) PipeRun(byte[][] inputs, double seco var counter = new KestrelBenchmark.ResponseCounter(JsonRpcPrefix); int cursor = 0, inFlight = 0; long received = 0; + var meter = CpuMeter.Start(); var sw = Stopwatch.StartNew(); while (sw.Elapsed.TotalSeconds < seconds) { @@ -337,11 +348,11 @@ private static (long count, double seconds) PipeRun(byte[][] inputs, double seco } sw.Stop(); toServer.Writer.Complete(); - return (received, sw.Elapsed.TotalSeconds); + return (received, sw.Elapsed.TotalSeconds, meter.Stop()); } /// A typed StreamJsonRpc proxy awaiting one call at a time over an in-process pipe pair: the usual way the library is used. - private static async Task<(long count, double seconds)> ProxyRun(double seconds) + private static async Task<(long count, double seconds, CpuUsage cpu)> ProxyRun(double seconds) { var toServer = new Pipe(); var toClient = new Pipe(); @@ -353,6 +364,7 @@ private static (long count, double seconds) PipeRun(byte[][] inputs, double seco client.StartListening(); long n = 0; + var meter = CpuMeter.Start(); var sw = Stopwatch.StartNew(); while (sw.Elapsed.TotalSeconds < seconds) { @@ -366,6 +378,6 @@ private static (long count, double seconds) PipeRun(byte[][] inputs, double seco sw.Stop(); toServer.Writer.Complete(); toClient.Writer.Complete(); - return (n, sw.Elapsed.TotalSeconds); + return (n, sw.Elapsed.TotalSeconds, meter.Stop()); } } diff --git a/TestServer_Console/CpuMeter.cs b/TestServer_Console/CpuMeter.cs new file mode 100644 index 0000000..e4945d3 --- /dev/null +++ b/TestServer_Console/CpuMeter.cs @@ -0,0 +1,177 @@ +using System; +using System.Diagnostics; +using System.IO; +using System.Linq; +using System.Runtime.InteropServices; + +namespace TestServer_Console; + +/// CPU consumed during one benchmark window, as a share of the cores available to the process. +internal readonly record struct CpuUsage(double? SystemPercent, double? ProcessPercent, double? ClientPercent, int Cores) +{ + internal string TrailingText => "cpu: system " + Format(SystemPercent) + ", process " + Format(ProcessPercent) + + (ClientPercent.HasValue ? ", clients " + Format(ClientPercent) : ""); + + private static string Format(double? value) => value.HasValue ? $"{value.Value:0.#} %" : "n/a"; +} + +/// Reads aggregate and process CPU counters only at the edges of a timed run. +internal sealed class CpuMeter +{ + private enum Source { None, Cgroup, ProcStat, Windows } + + private readonly long _started; + private readonly double? _processStart; + private readonly Source _source; + private readonly double _capacity; + private readonly ulong _systemStart; + private readonly ulong _systemTotalStart; + + private CpuMeter() + { + Cores = Environment.ProcessorCount; + _started = Stopwatch.GetTimestamp(); + _processStart = ProcessTime(); + if (OperatingSystem.IsLinux()) + { + if (TryQuota(out double quota)) + { + if (TryCgroupUsage(out _systemStart)) + { + _source = Source.Cgroup; + _capacity = quota; + } + } + else if (TryProcStat(out _systemStart, out _systemTotalStart)) + { + _source = Source.ProcStat; + } + } + else if (OperatingSystem.IsWindows() && TryWindowsSystem(out _systemStart, out _systemTotalStart)) + { + _source = Source.Windows; + } + } + + internal int Cores { get; } + + internal static CpuMeter Start() => new CpuMeter(); + + internal CpuUsage Stop(double? clientSeconds = null) + { + double wall = Stopwatch.GetElapsedTime(_started).TotalSeconds; + double? processEnd = ProcessTime(); + double? process = _processStart.HasValue && processEnd.HasValue + ? Percent(processEnd.Value - _processStart.Value, wall * Cores) : null; + double? system = null; + if (_source == Source.Cgroup && TryCgroupUsage(out ulong usage)) + system = Percent((usage - _systemStart) / 1_000_000.0, wall * _capacity); + else if (_source == Source.ProcStat && TryProcStat(out ulong busy, out ulong total)) + system = Percent(busy - _systemStart, total - _systemTotalStart); + else if (_source == Source.Windows && TryWindowsSystem(out ulong winBusy, out ulong winTotal)) + system = Percent(winBusy - _systemStart, winTotal - _systemTotalStart); + return new CpuUsage(system, process, clientSeconds.HasValue ? Percent(clientSeconds.Value, wall * Cores) : null, Cores); + } + + private static double Percent(double amount, double capacity) => capacity > 0 + ? Math.Clamp(100 * amount / capacity, 0, 100) : 0; + + private static double? ProcessTime() + { + try + { + using var process = Process.GetCurrentProcess(); + return process.TotalProcessorTime.TotalSeconds; + } + catch (Exception) { return null; } + } + + internal static bool TryQuota(out double cores) + { + cores = 0; + try + { + if (!File.Exists("/sys/fs/cgroup/cpu.max")) return false; + var parts = File.ReadAllText("/sys/fs/cgroup/cpu.max").Split((char[])null, StringSplitOptions.RemoveEmptyEntries); + if (parts.Length < 2 || parts[0] == "max" || + !double.TryParse(parts[0], System.Globalization.NumberStyles.Float, System.Globalization.CultureInfo.InvariantCulture, out double quota) || + !double.TryParse(parts[1], System.Globalization.NumberStyles.Float, System.Globalization.CultureInfo.InvariantCulture, out double period) || + quota <= 0 || period <= 0) return false; + cores = quota / period; + return true; + } + catch (Exception) { return false; } + } + + private static bool TryCgroupUsage(out ulong usage) + { + usage = 0; + try + { + var line = File.ReadLines("/sys/fs/cgroup/cpu.stat").FirstOrDefault(s => s.StartsWith("usage_usec ", StringComparison.Ordinal)); + return line != null && ulong.TryParse(line.AsSpan("usage_usec ".Length), out usage); + } + catch (Exception) { return false; } + } + + private static bool TryProcStat(out ulong busy, out ulong total) + { + busy = total = 0; + try + { + var parts = File.ReadLines("/proc/stat").First().Split((char[])null, StringSplitOptions.RemoveEmptyEntries); + if (parts.Length < 6 || parts[0] != "cpu") return false; + for (int i = 1; i < parts.Length; i++) + { + if (!ulong.TryParse(parts[i], out ulong value)) return false; + total += value; + } + busy = total - ulong.Parse(parts[4]) - ulong.Parse(parts[5]); + return true; + } + catch (Exception) { return false; } + } + + [StructLayout(LayoutKind.Sequential)] + private struct FileTime { internal uint Low; internal uint High; internal readonly ulong Value => ((ulong)High << 32) | Low; } + + private static bool TryWindowsSystem(out ulong busy, out ulong total) + { + busy = total = 0; + if (!GetSystemTimes(out var idle, out var kernel, out var user)) return false; + busy = kernel.Value - idle.Value + user.Value; + total = kernel.Value + user.Value; + return true; + } + + /// CPU seconds used by the calling thread; null when the platform cannot provide them. + internal static double? ThreadTime() + { + if (OperatingSystem.IsWindows()) + { + if (!GetThreadTimes(GetCurrentThread(), out _, out _, out var kernel, out var user)) return null; + return (kernel.Value + user.Value) / 10_000_000.0; + } + if (OperatingSystem.IsLinux()) + { + if (clock_gettime(3, out var time) != 0) return null; // CLOCK_THREAD_CPUTIME_ID + return time.Seconds + time.Nanoseconds / 1_000_000_000.0; + } + return null; + } + + [StructLayout(LayoutKind.Sequential)] + private struct Timespec { internal long Seconds; internal long Nanoseconds; } + + [DllImport("kernel32.dll")] + private static extern bool GetSystemTimes(out FileTime idle, out FileTime kernel, out FileTime user); + + [DllImport("kernel32.dll")] + private static extern IntPtr GetCurrentThread(); + + [DllImport("kernel32.dll")] + private static extern bool GetThreadTimes(IntPtr thread, out FileTime creation, out FileTime exit, out FileTime kernel, out FileTime user); + + [DllImport("libc", EntryPoint = "clock_gettime")] + private static extern int clock_gettime(int clockId, out Timespec time); +} diff --git a/TestServer_Console/GrpcCompare.cs b/TestServer_Console/GrpcCompare.cs index e658b92..e9fb35e 100644 --- a/TestServer_Console/GrpcCompare.cs +++ b/TestServer_Console/GrpcCompare.cs @@ -125,7 +125,7 @@ private static GrpcChannel[] OpenChannels(int port, int count) /// Unary calls: HTTP/2 connections, each with workers /// that await one call at a time, so at most channels × inFlight calls are outstanding. /// - internal static async Task<(long count, double seconds)> UnaryRun(int port, int channels, int inFlight, double seconds) + internal static async Task<(long count, double seconds, CpuUsage cpu)> UnaryRun(int port, int channels, int inFlight, double seconds) { var chans = OpenChannels(port, channels); try @@ -135,6 +135,7 @@ private static GrpcChannel[] OpenChannels(int port, int count) var counts = new long[channels * inFlight]; using var stop = new CancellationTokenSource(); + var meter = CpuMeter.Start(); var sw = Stopwatch.StartNew(); var workers = new Task[counts.Length]; for (int i = 0; i < workers.Length; i++) @@ -154,7 +155,7 @@ private static GrpcChannel[] OpenChannels(int port, int count) stop.Cancel(); await Task.WhenAll(workers); sw.Stop(); - return (counts.Sum(), sw.Elapsed.TotalSeconds); + return (counts.Sum(), sw.Elapsed.TotalSeconds, meter.Stop()); } finally { @@ -168,13 +169,14 @@ private static GrpcChannel[] OpenChannels(int port, int count) /// client, the writer sends whatever has room as one batch: BufferHint on every message but the last, which /// flushes. The server answers each message as it arrives (gRPC's default write, one flush per reply). /// - internal static async Task<(long count, double seconds)> StreamRun(int port, int channels, int inFlight, double seconds) + internal static async Task<(long count, double seconds, CpuUsage cpu)> StreamRun(int port, int channels, int inFlight, double seconds) { var chans = OpenChannels(port, channels); try { var counts = new long[channels]; using var stop = new CancellationTokenSource(); + var meter = CpuMeter.Start(); var sw = Stopwatch.StartNew(); var streams = new Task[channels]; for (int i = 0; i < channels; i++) @@ -217,7 +219,7 @@ private static GrpcChannel[] OpenChannels(int port, int count) stop.Cancel(); await Task.WhenAll(streams); sw.Stop(); - return (counts.Sum(), sw.Elapsed.TotalSeconds); + return (counts.Sum(), sw.Elapsed.TotalSeconds, meter.Stop()); } finally { diff --git a/TestServer_Console/KestrelBenchmark.cs b/TestServer_Console/KestrelBenchmark.cs index 888e475..2345b23 100644 --- a/TestServer_Console/KestrelBenchmark.cs +++ b/TestServer_Console/KestrelBenchmark.cs @@ -72,29 +72,29 @@ internal static async Task RunAsync(Action print, double seconds = 3, in var memInputs = inputs.Select(i => (ReadOnlyMemory)i).ToArray(); // Scale rows: the same requests with no transport at all. - BenchmarkRunner.RunSync(session, memInputs, Config.Serializer, 1, 0.5, out _); // warm-up - var elapsed = BenchmarkRunner.RunSync(session, memInputs, Config.Serializer, 1, seconds, out long total); - rows.Add(new BenchmarkRunner.ChartRow("in-process, 1 thread", total / elapsed, $"{total,12:N0} RPCs")); - elapsed = BenchmarkRunner.RunSync(session, memInputs, Config.Serializer, clients, seconds, out total); - rows.Add(new BenchmarkRunner.ChartRow($"in-process, {clients} threads", total / elapsed, $"{total,12:N0} RPCs")); + BenchmarkRunner.RunSync(session, memInputs, Config.Serializer, 1, 0.5); // warm-up + var (total, elapsed, cpu) = BenchmarkRunner.RunSync(session, memInputs, Config.Serializer, 1, seconds); + rows.Add(new BenchmarkRunner.ChartRow("in-process, 1 thread", total / elapsed, $"{total,12:N0} RPCs {cpu.TrailingText}")); + (total, elapsed, cpu) = BenchmarkRunner.RunSync(session, memInputs, Config.Serializer, clients, seconds); + rows.Add(new BenchmarkRunner.ChartRow($"in-process, {clients} threads", total / elapsed, $"{total,12:N0} RPCs {cpu.TrailingText}")); print($" in-process rows done ({rows[0].RpcPerSec:N0} / {rows[1].RpcPerSec:N0} RPC/s)"); // HTTP, one request per POST. await HttpRun(httpUrl, inputs, 1, clients, 0.5); // warm-up - var (count, secs) = await HttpRun(httpUrl, inputs, 1, clients, seconds); - rows.Add(new BenchmarkRunner.ChartRow("HTTP, 1 request/POST", count / secs, $"{count,12:N0} RPCs {secs / count * 1e6 * clients:N1} us/request per client")); + var (count, secs, usage) = await HttpRun(httpUrl, inputs, 1, clients, seconds); + rows.Add(new BenchmarkRunner.ChartRow("HTTP, 1 request/POST", count / secs, $"{count,12:N0} RPCs {secs / count * 1e6 * clients:N1} us/request per client {usage.TrailingText}")); print($" HTTP single done ({count / secs:N0} RPC/s)"); // HTTP, a batch per POST. await HttpRun(httpUrl, new[] { batch }, batchSize, clients, 0.5); - (count, secs) = await HttpRun(httpUrl, new[] { batch }, batchSize, clients, seconds); - rows.Add(new BenchmarkRunner.ChartRow($"HTTP, batch of {batchSize}/POST", count / secs, $"{count,12:N0} RPCs")); + (count, secs, usage) = await HttpRun(httpUrl, new[] { batch }, batchSize, clients, seconds); + rows.Add(new BenchmarkRunner.ChartRow($"HTTP, batch of {batchSize}/POST", count / secs, $"{count,12:N0} RPCs {usage.TrailingText}")); print($" HTTP batch done ({count / secs:N0} RPC/s)"); // TCP, pipelined. TcpRun(tcpPort, inputs, clients, 0.5, pipeline, ResultPrefix); - (count, secs) = TcpRun(tcpPort, inputs, clients, seconds, pipeline, ResultPrefix); - rows.Add(new BenchmarkRunner.ChartRow($"TCP, {pipeline} pipelined{(asyncMethods ? ", inline methods" : "")}", count / secs, $"{count,12:N0} RPCs")); + (count, secs, usage) = TcpRun(tcpPort, inputs, clients, seconds, pipeline, ResultPrefix); + rows.Add(new BenchmarkRunner.ChartRow($"TCP, {pipeline} pipelined{(asyncMethods ? ", inline methods" : "")}", count / secs, $"{count,12:N0} RPCs {usage.TrailingText}")); print($" TCP done ({count / secs:N0} RPC/s)"); if (asyncMethods) @@ -102,8 +102,8 @@ internal static async Task RunAsync(Action print, double seconds = 3, in // The same five calls, each answered by a method that awaits Task.Yield() before returning. var yieldInputs = inputs.Select(i => Encoding.UTF8.GetBytes(Encoding.UTF8.GetString(i).Replace("\"method\":\"", "\"method\":\"" + YieldPrefix))).ToArray(); TcpRun(tcpPort, yieldInputs, clients, 0.5, pipeline, ResultPrefix); - (count, secs) = TcpRun(tcpPort, yieldInputs, clients, seconds, pipeline, ResultPrefix); - rows.Add(new BenchmarkRunner.ChartRow($"TCP, {pipeline} pipelined, yielding methods", count / secs, $"{count,12:N0} RPCs")); + (count, secs, usage) = TcpRun(tcpPort, yieldInputs, clients, seconds, pipeline, ResultPrefix); + rows.Add(new BenchmarkRunner.ChartRow($"TCP, {pipeline} pipelined, yielding methods", count / secs, $"{count,12:N0} RPCs {usage.TrailingText}")); print($" TCP yielding done ({count / secs:N0} RPC/s)"); } @@ -146,13 +146,14 @@ internal static byte[] BuildBatch(byte[][] inputs, int size) } /// Each client POSTs its next document, reads the body, checks it is a result, and repeats. - internal static async Task<(long count, double seconds)> HttpRun(string url, byte[][] documents, int rpcsPerDocument, int clients, double seconds) + internal static async Task<(long count, double seconds, CpuUsage cpu)> HttpRun(string url, byte[][] documents, int rpcsPerDocument, int clients, double seconds) { using var handler = new SocketsHttpHandler { MaxConnectionsPerServer = clients * 2, PooledConnectionLifetime = TimeSpan.FromMinutes(5) }; using var http = new HttpClient(handler); var prefix = rpcsPerDocument > 1 ? BatchResultPrefix : ResultPrefix; using var cts = new CancellationTokenSource(); var counts = new long[clients]; + var meter = CpuMeter.Start(); var sw = Stopwatch.StartNew(); var tasks = new Task[clients]; @@ -182,7 +183,7 @@ internal static byte[] BuildBatch(byte[][] inputs, int size) cts.Cancel(); await Task.WhenAll(tasks); sw.Stop(); - return (counts.Sum(), sw.Elapsed.TotalSeconds); + return (counts.Sum(), sw.Elapsed.TotalSeconds, meter.Stop()); } /// @@ -193,13 +194,14 @@ internal static byte[] BuildBatch(byte[][] inputs, int size) /// no allocation and no parsing beyond bracket depth. /// /// Bytes every response must start with, or null to skip the check (framings that put headers first). - internal static (long count, double seconds) TcpRun(int port, byte[][] inputs, int clients, double seconds, int pipeline, byte[] expectedPrefix) + internal static (long count, double seconds, CpuUsage cpu) TcpRun(int port, byte[][] inputs, int clients, double seconds, int pipeline, byte[] expectedPrefix) { const int ringCount = 4096; var offsets = new int[ringCount + pipeline + 1]; var ring = BuildRing(inputs, ringCount, pipeline, offsets); var counts = new long[clients]; + var clientTimes = new double?[clients]; int stop = 0; Exception failure = null; var ready = new Barrier(clients + 1); @@ -221,6 +223,7 @@ internal static (long count, double seconds) TcpRun(int port, byte[][] inputs, i long received = 0; ready.SignalAndWait(); + double? cpuStart = CpuMeter.ThreadTime(); while (Volatile.Read(ref stop) == 0) { int free = pipeline - inFlight; @@ -257,6 +260,8 @@ internal static (long count, double seconds) TcpRun(int port, byte[][] inputs, i } catch (SocketException) { } + double? cpuEnd = CpuMeter.ThreadTime(); + if (cpuStart.HasValue && cpuEnd.HasValue) clientTimes[slot] = cpuEnd.Value - cpuStart.Value; counts[slot] = received; } catch (Exception e) @@ -269,6 +274,7 @@ internal static (long count, double seconds) TcpRun(int port, byte[][] inputs, i } ready.SignalAndWait(); + var meter = CpuMeter.Start(); var sw = Stopwatch.StartNew(); Thread.Sleep(TimeSpan.FromSeconds(seconds)); Volatile.Write(ref stop, 1); @@ -276,7 +282,8 @@ internal static (long count, double seconds) TcpRun(int port, byte[][] inputs, i sw.Stop(); if (failure != null) throw new InvalidOperationException("TCP client failed", failure); - return (counts.Sum(), sw.Elapsed.TotalSeconds); + double? clientSeconds = clientTimes.All(v => v.HasValue) ? clientTimes.Sum(v => v.Value) : null; + return (counts.Sum(), sw.Elapsed.TotalSeconds, meter.Stop(clientSeconds)); } /// diff --git a/TestServer_Console/PrintHardware.cs b/TestServer_Console/PrintHardware.cs index 5653293..173b085 100644 --- a/TestServer_Console/PrintHardware.cs +++ b/TestServer_Console/PrintHardware.cs @@ -1,12 +1,18 @@ using System; using System.Collections.Generic; +using System.IO; +using System.Linq; +using System.Runtime; using System.Runtime.InteropServices; using System.Runtime.Versioning; using System.Text; using Hardware.Info; +using TestServer_Console; public class HardwarePrinter { + /// The console row the hardware box is drawn from: the first row after the machine description. + internal static int TopRow; private static readonly StringBuilder sb = new StringBuilder(8192); // Preallocate generous capacity for reuse @@ -152,7 +158,7 @@ internal static void PrintHardware(IHardwareInfo hardwareInfo) // Single write to console if (!Console.IsOutputRedirected) { - Console.SetCursorPosition(0, 0); + Console.SetCursorPosition(0, TopRow); // Below the machine description, however many lines it wrapped to. } Console.Write(sb.ToString()); } @@ -177,4 +183,45 @@ static string GetUsageAnsi(double percent) [SupportedOSPlatform("windows")] [DllImport("kernel32.dll")] private static extern bool SetConsoleMode(IntPtr hConsoleHandle, uint dwMode); -} \ No newline at end of file +} + +/// Describes the CPU capacity and runtime used for a benchmark run. +internal static class MachineDescription +{ + internal static string Current() + { + var overridden = Environment.GetEnvironmentVariable("JSONRPC_BENCH_MACHINE"); + if (!string.IsNullOrWhiteSpace(overridden)) return overridden; + + string model = Environment.GetEnvironmentVariable("PROCESSOR_IDENTIFIER") ?? RuntimeInformation.ProcessArchitecture.ToString(); + int hostCpus = 0; + if (OperatingSystem.IsLinux()) + { + try + { + foreach (var line in File.ReadLines("/proc/cpuinfo")) + { + if (line.StartsWith("model name", StringComparison.Ordinal) && model == (Environment.GetEnvironmentVariable("PROCESSOR_IDENTIFIER") ?? RuntimeInformation.ProcessArchitecture.ToString())) + model = line.Split(':', 2)[1].Trim(); + if (line.StartsWith("processor", StringComparison.Ordinal) && line.Contains(':')) hostCpus++; + } + } + catch (IOException) { } + } + else if (OperatingSystem.IsWindows()) + { + try + { + var info = new HardwareInfo(); + info.RefreshAll(); + model = info.CpuList.FirstOrDefault()?.Name?.Trim() ?? model; // WMI pads the name with spaces + } + catch (Exception) { } // WMI can be denied in a restricted runner. + } + + string capacity = Environment.ProcessorCount + " cores"; + if (OperatingSystem.IsLinux() && CpuMeter.TryQuota(out _) && hostCpus > 0) + capacity += $" of {hostCpus} host CPUs, cgroup quota"; + return $"{model}, {capacity}, {RuntimeInformation.OSDescription}, {RuntimeInformation.FrameworkDescription}, Release, {(GCSettings.IsServerGC ? "Server GC" : "Workstation GC")}"; + } +} diff --git a/TestServer_Console/Program.cs b/TestServer_Console/Program.cs index 649e84e..4fec7ce 100644 --- a/TestServer_Console/Program.cs +++ b/TestServer_Console/Program.cs @@ -15,6 +15,11 @@ static void Main(string[] args) services = new object[] { new CalculatorService() }; // Before any mode runs: the awaited-worker modes (--async, --scale) start their workers on the pool. System.Threading.ThreadPool.SetMinThreads(Environment.ProcessorCount * 3, Environment.ProcessorCount * 3); + var interactive = !Console.IsOutputRedirected; + if (interactive) Console.Clear(); + Console.WriteLine("Machine: " + MachineDescription.Current()); + if (interactive) HardwarePrinter.TopRow = Console.CursorTop; + if (args.Length > 0 && args[0] == "--machine") return; // `dotnet run -- --async [seconds] [workers]` drives ProcessAsync from awaited workers (the Async table). if (args.Length > 0 && args[0] == "--async") @@ -41,11 +46,14 @@ static void Main(string[] args) return; } - var interactive = !Console.IsOutputRedirected; - if (interactive) Console.Clear(); - IHardwareInfo hardwareInfo = new HardwareInfo(); - hardwareInfo.RefreshAll(); - HardwarePrinter.PrintHardware(hardwareInfo); + IHardwareInfo hardwareInfo = null; + try + { + hardwareInfo = new HardwareInfo(); + hardwareInfo.RefreshAll(); + HardwarePrinter.PrintHardware(hardwareInfo); + } + catch (Exception) { hardwareInfo = null; } // A restricted runner may deny WMI. Console.WriteLine("Thread pool minimum set to {0}", Environment.ProcessorCount * 3); // `dotnet run -- --sync [seconds] [threads]` runs the direct synchronous benchmark and exits (CI / scripted runs). @@ -122,7 +130,7 @@ private static void LegacyStringBenchmark(bool interactive, IHardwareInfo hardwa return; } Console.CursorVisible = false; - HardwarePrinter.PrintHardware(hardwareInfo); + if (hardwareInfo != null) HardwarePrinter.PrintHardware(hardwareInfo); var pos = Console.CursorTop; BenchmarkRunner.Benchmark((update) => { diff --git a/benchmarks/charts/explorer.html b/benchmarks/charts/explorer.html index a633976..20af779 100644 --- a/benchmarks/charts/explorer.html +++ b/benchmarks/charts/explorer.html @@ -100,6 +100,7 @@

Snapshot sets from the README

return String(v); } function exact(v) { return Math.round(v).toLocaleString("en-US"); } + function cpuValue(p, key) { return p.cpu && p.cpu[key] != null ? p.cpu[key] + " %" : ""; } function el(tag, attrs, parent) { var e = document.createElementNS(NS, tag); for (var k in attrs) e.setAttribute(k, attrs[k]); @@ -284,13 +285,14 @@

Snapshot sets from the README

var i = conns.indexOf(+sel.value), t = document.getElementById("at-conn"); t.innerHTML = ""; var h = html("tr", {}, html("thead", {}, t)); - ["series", "concurrency", "median RPC/s", "low", "high", "n"].forEach(function (c) { html("th", { scope: "col" }, h, c); }); + ["series", "concurrency", "median RPC/s", "low", "high", "n", "system CPU %", "process CPU %", "client CPU %"].forEach(function (c) { html("th", { scope: "col" }, h, c); }); var b = html("tbody", {}, t); sweep.series.forEach(function (s) { var p = s.points[i], r = html("tr", {}, b); html("td", {}, r, familyNames[s.family] + ", " + s.label); html("td", { style: "text-align:left" }, r, s.concurrency); html("td", {}, r, exact(p.median)); html("td", {}, r, exact(p.low)); html("td", {}, r, exact(p.high)); html("td", {}, r, p.n); + ["system", "process", "clients"].forEach(function (key) { html("td", {}, r, cpuValue(p, key)); }); }); } sel.addEventListener("change", atConn); @@ -300,7 +302,7 @@

Snapshot sets from the README

(function () { var t = document.getElementById("sweep-table"); var h = html("tr", {}, html("thead", {}, t)); - ["series", "connections", "low", "median", "high", "observations (one per run)"].forEach(function (c) { html("th", { scope: "col" }, h, c); }); + ["series", "connections", "low", "median", "high", "observations (one per run)", "system CPU %", "process CPU %", "client CPU %"].forEach(function (c) { html("th", { scope: "col" }, h, c); }); var b = html("tbody", {}, t); sweep.series.forEach(function (s) { s.points.forEach(function (p, i) { @@ -309,6 +311,7 @@

Snapshot sets from the README

html("td", {}, r, conns[i]); html("td", {}, r, exact(p.low)); html("td", {}, r, exact(p.median)); html("td", {}, r, exact(p.high)); html("td", {}, r, p.values.map(exact).join(", ")); + ["system", "process", "clients"].forEach(function (key) { html("td", {}, r, cpuValue(p, key)); }); }); }); })(); diff --git a/benchmarks/charts/explorer_template.html b/benchmarks/charts/explorer_template.html index 0cb1f69..ac4edb5 100644 --- a/benchmarks/charts/explorer_template.html +++ b/benchmarks/charts/explorer_template.html @@ -100,6 +100,7 @@

Snapshot sets from the README

return String(v); } function exact(v) { return Math.round(v).toLocaleString("en-US"); } + function cpuValue(p, key) { return p.cpu && p.cpu[key] != null ? p.cpu[key] + " %" : ""; } function el(tag, attrs, parent) { var e = document.createElementNS(NS, tag); for (var k in attrs) e.setAttribute(k, attrs[k]); @@ -284,13 +285,14 @@

Snapshot sets from the README

var i = conns.indexOf(+sel.value), t = document.getElementById("at-conn"); t.innerHTML = ""; var h = html("tr", {}, html("thead", {}, t)); - ["series", "concurrency", "median RPC/s", "low", "high", "n"].forEach(function (c) { html("th", { scope: "col" }, h, c); }); + ["series", "concurrency", "median RPC/s", "low", "high", "n", "system CPU %", "process CPU %", "client CPU %"].forEach(function (c) { html("th", { scope: "col" }, h, c); }); var b = html("tbody", {}, t); sweep.series.forEach(function (s) { var p = s.points[i], r = html("tr", {}, b); html("td", {}, r, familyNames[s.family] + ", " + s.label); html("td", { style: "text-align:left" }, r, s.concurrency); html("td", {}, r, exact(p.median)); html("td", {}, r, exact(p.low)); html("td", {}, r, exact(p.high)); html("td", {}, r, p.n); + ["system", "process", "clients"].forEach(function (key) { html("td", {}, r, cpuValue(p, key)); }); }); } sel.addEventListener("change", atConn); @@ -300,7 +302,7 @@

Snapshot sets from the README

(function () { var t = document.getElementById("sweep-table"); var h = html("tr", {}, html("thead", {}, t)); - ["series", "connections", "low", "median", "high", "observations (one per run)"].forEach(function (c) { html("th", { scope: "col" }, h, c); }); + ["series", "connections", "low", "median", "high", "observations (one per run)", "system CPU %", "process CPU %", "client CPU %"].forEach(function (c) { html("th", { scope: "col" }, h, c); }); var b = html("tbody", {}, t); sweep.series.forEach(function (s) { s.points.forEach(function (p, i) { @@ -309,6 +311,7 @@

Snapshot sets from the README

html("td", {}, r, conns[i]); html("td", {}, r, exact(p.low)); html("td", {}, r, exact(p.median)); html("td", {}, r, exact(p.high)); html("td", {}, r, p.values.map(exact).join(", ")); + ["system", "process", "clients"].forEach(function (key) { html("td", {}, r, cpuValue(p, key)); }); }); }); })(); diff --git a/benchmarks/charts/render.py b/benchmarks/charts/render.py index 6a11160..9f8b5bd 100644 --- a/benchmarks/charts/render.py +++ b/benchmarks/charts/render.py @@ -78,6 +78,7 @@ def fold_sweep(sweep, runs, names): if r["connections"] != xs: raise DataError("sweep runs disagree on the connection counts") by_name = {s["name"]: [] for s in sweep["series"]} + cpu_by_name = {s["name"]: [] for s in sweep["series"]} for r in runs: seen = set() for s in r["series"]: @@ -85,7 +86,11 @@ def fold_sweep(sweep, runs, names): raise DataError(f"sweep run has an unknown series {s['name']!r}; add it to benchmarks.json") if len(s["rpcPerSec"]) != len(xs): raise DataError(f"sweep series {s['name']!r} has {len(s['rpcPerSec'])} values for {len(xs)} connection counts") + for field in ("cpuSystem", "cpuProcess", "cpuClients"): + if field in s and len(s[field]) != len(xs): + raise DataError(f"sweep series {s['name']!r} has {len(s[field])} {field} values for {len(xs)} connection counts") by_name[s["name"]].append(s["rpcPerSec"]) + cpu_by_name[s["name"]].append(s) seen.add(s["name"]) missing = set(by_name) - seen if missing: @@ -96,10 +101,23 @@ def fold_sweep(sweep, runs, names): sweep["pipeline"] = first["pipeline"] sweep["date"] = ", ".join(sorted({r["date"] for r in runs})) sweep["machine"] = first["machine"] + cores = {r["cores"] for r in runs if "cores" in r} + if len(cores) > 1: + raise DataError("sweep runs disagree on available cores") + if cores: + sweep["cores"] = cores.pop() for s in sweep["series"]: cols = list(zip(*by_name[s["name"]])) s["points"] = [dict(low=min(c), high=max(c), median=statistics.median(c), n=len(c), values=list(c), status="range" if len(c) > 1 else "single") for c in cols] + for i, point in enumerate(s["points"]): + cpu = {} + for field, label in (("cpuSystem", "system"), ("cpuProcess", "process"), ("cpuClients", "clients")): + values = [run[field][i] for run in cpu_by_name[s["name"]] if field in run and run[field][i] is not None] + if values: + cpu[label] = statistics.median(values) + if cpu: + point["cpu"] = cpu def validate(data): diff --git a/benchmarks/charts/test_render.py b/benchmarks/charts/test_render.py index ce40d2f..77bc095 100644 --- a/benchmarks/charts/test_render.py +++ b/benchmarks/charts/test_render.py @@ -83,6 +83,33 @@ def test_sweep_run_mismatch(self): with self.assertRaises(render.DataError): render.fold_sweep(sweep, runs, ["a"]) + def test_sweep_cpu_arrays_and_older_runs(self): + sweep = copy.deepcopy(self.data["sets"]["sweep"]) + def run(with_cpu): + series = [] + for s in sweep["series"]: + cell = dict(name=s["name"], rpcPerSec=[100, 200]) + if with_cpu: + cell.update(cpuSystem=[80.1, 90.2], cpuProcess=[70.0, 85.0], + cpuClients=[30.0, None] if "TCP" in s["name"] else [None, None]) + series.append(cell) + return dict(connections=[1, 2], secondsPerCell=2, pipeline=256, date="d", machine="m", + **({"cores": 2} if with_cpu else {}), series=series) + render.fold_sweep(sweep, [run(True), run(True)], ["a", "b"]) + self.assertEqual(sweep["cores"], 2) + self.assertEqual(sweep["series"][0]["points"][0]["cpu"], + dict(system=80.1, process=70.0, clients=30.0)) + self.assertEqual(sweep["series"][0]["points"][1]["cpu"], dict(system=90.2, process=85.0)) + old = copy.deepcopy(self.data["sets"]["sweep"]) + render.fold_sweep(old, [run(False)], ["old"]) + self.assertNotIn("cores", old) + self.assertNotIn("cpu", old["series"][0]["points"][0]) + + bad = run(True) + bad["series"][0]["cpuSystem"].pop() + with self.assertRaises(render.DataError): + render.fold_sweep(copy.deepcopy(self.data["sets"]["sweep"]), [bad], ["bad"]) + class Outputs(unittest.TestCase): @classmethod diff --git a/benchmarks/hf/fetch.py b/benchmarks/hf/fetch.py new file mode 100644 index 0000000..cb39b8d --- /dev/null +++ b/benchmarks/hf/fetch.py @@ -0,0 +1,51 @@ +"""Fetch a Hugging Face Job's UTF-8 log and framed sweep JSON files.""" +import argparse +import json +import pathlib +import re +import subprocess + + +FRAME = re.compile(r"^== BEGIN (sweep-[1-9][0-9]*\.json)$") + + +def main(): + parser = argparse.ArgumentParser(description=__doc__) + parser.add_argument("job_id") + parser.add_argument("out_dir", type=pathlib.Path) + args = parser.parse_args() + + result = subprocess.run(["hf", "jobs", "logs", args.job_id], stdout=subprocess.PIPE, + stderr=subprocess.PIPE, check=False) + if result.returncode: + raise SystemExit(result.stderr.decode("utf-8", errors="replace")) + log = result.stdout.decode("utf-8", errors="replace") + args.out_dir.mkdir(parents=True, exist_ok=True) + (args.out_dir / "job.log").write_text(log, encoding="utf-8") + + lines = log.splitlines() + index = 0 + written = 0 + while index < len(lines): + match = FRAME.fullmatch(lines[index]) + if not match: + index += 1 + continue + name = match.group(1) + end = f"== END {name}" + try: + last = lines.index(end, index + 1) + except ValueError as exc: + raise SystemExit(f"missing {end}") from exc + content = "\n".join(lines[index + 1:last]) + "\n" + json.loads(content) + (args.out_dir / name).write_text(content, encoding="utf-8") + print(args.out_dir / name) + written += 1 + index = last + 1 + if not written: + raise SystemExit(f"no '== BEGIN sweep-.json' frame in the log; see {args.out_dir / 'job.log'}") + + +if __name__ == "__main__": + main() diff --git a/benchmarks/hf/launch.sh b/benchmarks/hf/launch.sh new file mode 100644 index 0000000..9aa9396 --- /dev/null +++ b/benchmarks/hf/launch.sh @@ -0,0 +1,18 @@ +#!/usr/bin/env bash +set -euo pipefail + +if [[ $# -lt 2 || $# -gt 3 ]]; then + echo "usage: launch.sh [runs]" >&2 + exit 2 +fi +ref=$1 +flavor=$2 +runs=${3:-3} +if ! [[ $runs =~ ^[1-9][0-9]*$ ]]; then + echo "runs must be a positive integer" >&2 + exit 2 +fi + +hf jobs run --detach --flavor "$flavor" --timeout 2h --name "jsonrpc-bench-$flavor" mcr.microsoft.com/dotnet/sdk:10.0 bash -lc \ + 'git clone https://github.com/Astn/JSON-RPC.NET.git /tmp/jsonrpc-runner && git -C /tmp/jsonrpc-runner fetch origin "$1" && git -C /tmp/jsonrpc-runner checkout --detach FETCH_HEAD && exec bash /tmp/jsonrpc-runner/benchmarks/hf/run.sh "$1" "$2"' \ + bash "$ref" "$runs" diff --git a/benchmarks/hf/run.sh b/benchmarks/hf/run.sh new file mode 100644 index 0000000..dcc489b --- /dev/null +++ b/benchmarks/hf/run.sh @@ -0,0 +1,52 @@ +#!/usr/bin/env bash +set -euo pipefail + +if [[ $# -lt 1 || $# -gt 2 ]]; then + echo "usage: run.sh [runs]" >&2 + exit 2 +fi +ref=$1 +runs=${2:-3} +if ! [[ $runs =~ ^[1-9][0-9]*$ ]]; then + echo "runs must be a positive integer" >&2 + exit 2 +fi + +cores=$(nproc) +if [[ -r /sys/fs/cgroup/cpu.max ]]; then + read -r quota period < /sys/fs/cgroup/cpu.max + if [[ $quota =~ ^[0-9]+$ && $period =~ ^[1-9][0-9]*$ ]]; then + cores=$(((quota + period - 1) / period)) + fi +fi + +work=$(mktemp -d) +git clone https://github.com/Astn/JSON-RPC.NET.git "$work" +git -C "$work" fetch origin "$ref" +git -C "$work" checkout --detach FETCH_HEAD +cd "$work" +dotnet build -c Release TestServer_Console -nodeReuse:false +dotnet run -c Release --no-build --project TestServer_Console -- --machine + +run_mode() { + dotnet run -c Release --no-build --project TestServer_Console -- "$@" +} + +scale_status=0 +run_mode --scale 3 "$cores" 4.0 || scale_status=$? +printf 'Scale gate exit code: %s\n' "$scale_status" +run_mode --sync 3 +run_mode --async 3 1 +run_mode --async 3 "$cores" +run_mode --kestrel 3 +run_mode --kestrel 3 async +run_mode --compare 3 + +mkdir -p /results +for ((k = 1; k <= runs; k++)); do + name="sweep-$k.json" + run_mode --sweep 2 "/results/$name" + printf '== BEGIN %s\n' "$name" + cat "/results/$name" + printf '== END %s\n' "$name" +done From 2c6aae19d141712e803f30d115280e8c1ea9ec17 Mon Sep 17 00:00:00 2001 From: Austin Harris Date: Sun, 27 Sep 2026 16:05:48 -0600 Subject: [PATCH 2/4] AUS-1011: Pass bash -c, not -lc, to hf jobs run The hf CLI parses -l as its own --label option, so the container received bash with the script as a file name and every job failed with exit 127. --- benchmarks/hf/launch.sh | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/benchmarks/hf/launch.sh b/benchmarks/hf/launch.sh index 9aa9396..de0bd25 100644 --- a/benchmarks/hf/launch.sh +++ b/benchmarks/hf/launch.sh @@ -13,6 +13,6 @@ if ! [[ $runs =~ ^[1-9][0-9]*$ ]]; then exit 2 fi -hf jobs run --detach --flavor "$flavor" --timeout 2h --name "jsonrpc-bench-$flavor" mcr.microsoft.com/dotnet/sdk:10.0 bash -lc \ +hf jobs run --detach --flavor "$flavor" --timeout 2h --name "jsonrpc-bench-$flavor" mcr.microsoft.com/dotnet/sdk:10.0 bash -c \ 'git clone https://github.com/Astn/JSON-RPC.NET.git /tmp/jsonrpc-runner && git -C /tmp/jsonrpc-runner fetch origin "$1" && git -C /tmp/jsonrpc-runner checkout --detach FETCH_HEAD && exec bash /tmp/jsonrpc-runner/benchmarks/hf/run.sh "$1" "$2"' \ bash "$ref" "$runs" From 6e33700987b0086cdbe6929a2397f19d95d213da Mon Sep 17 00:00:00 2001 From: Austin Harris Date: Sun, 27 Sep 2026 16:11:16 -0600 Subject: [PATCH 3/4] AUS-1011: Accept a branch, tag or any commit as the job ref git fetch refuses a short hash, which is what the first launch passed. The runner now fetches when it can and otherwise checks the ref out from the full clone; the README and the usage lines say what a ref may be. --- README.md | 2 +- benchmarks/hf/launch.sh | 4 ++-- benchmarks/hf/run.sh | 6 +++--- 3 files changed, 6 insertions(+), 6 deletions(-) diff --git a/README.md b/README.md index 91f890a..94fe1d6 100644 --- a/README.md +++ b/README.md @@ -630,7 +630,7 @@ dotnet run --project samples/WasmHost # browser: " The three modes measure different things and are named for the entry point they call. `Process(bytes), dedicated threads` measures the library alone. `ProcessAsync(bytes), awaited workers` measures the entry point an asynchronous host calls. `Legacy Process(string), scheduled synchronous work` measures the 1.x string overloads through the thread pool. The Kestrel rows say whether `EnableAsyncMethods` was on. -On Hugging Face Jobs, run `benchmarks/hf/launch.sh [runs]` and retrieve JSON with `benchmarks/hf/fetch.py `; `cpu-upgrade` is 8 vCPU ($0.03/h), `cpu-xl` is 16 vCPU ($1/h), and `cpu-performance` is 32 vCPU ($1.90/h), while `cpu-basic` is 2 vCPU for smoke runs only. These are shared vCPUs, so each job's figures belong to its own machine row and are never merged into the reference-box tables. +On Hugging Face Jobs, run `benchmarks/hf/launch.sh [runs]` (`` is a branch, tag or commit) and retrieve JSON with `benchmarks/hf/fetch.py `; `cpu-upgrade` is 8 vCPU ($0.03/h), `cpu-xl` is 16 vCPU ($1/h), and `cpu-performance` is 32 vCPU ($1.90/h), while `cpu-basic` is 2 vCPU for smoke runs only. These are shared vCPUs, so each job's figures belong to its own machine row and are never merged into the reference-box tables. ### Sync: the library alone diff --git a/benchmarks/hf/launch.sh b/benchmarks/hf/launch.sh index de0bd25..021a693 100644 --- a/benchmarks/hf/launch.sh +++ b/benchmarks/hf/launch.sh @@ -2,7 +2,7 @@ set -euo pipefail if [[ $# -lt 2 || $# -gt 3 ]]; then - echo "usage: launch.sh [runs]" >&2 + echo "usage: launch.sh [runs]" >&2 exit 2 fi ref=$1 @@ -14,5 +14,5 @@ if ! [[ $runs =~ ^[1-9][0-9]*$ ]]; then fi hf jobs run --detach --flavor "$flavor" --timeout 2h --name "jsonrpc-bench-$flavor" mcr.microsoft.com/dotnet/sdk:10.0 bash -c \ - 'git clone https://github.com/Astn/JSON-RPC.NET.git /tmp/jsonrpc-runner && git -C /tmp/jsonrpc-runner fetch origin "$1" && git -C /tmp/jsonrpc-runner checkout --detach FETCH_HEAD && exec bash /tmp/jsonrpc-runner/benchmarks/hf/run.sh "$1" "$2"' \ + 'git clone https://github.com/Astn/JSON-RPC.NET.git /tmp/jsonrpc-runner && (git -C /tmp/jsonrpc-runner fetch origin "$1" && git -C /tmp/jsonrpc-runner checkout --detach FETCH_HEAD || git -C /tmp/jsonrpc-runner checkout --detach "$1") && exec bash /tmp/jsonrpc-runner/benchmarks/hf/run.sh "$1" "$2"' \ bash "$ref" "$runs" diff --git a/benchmarks/hf/run.sh b/benchmarks/hf/run.sh index dcc489b..154bd8f 100644 --- a/benchmarks/hf/run.sh +++ b/benchmarks/hf/run.sh @@ -2,7 +2,7 @@ set -euo pipefail if [[ $# -lt 1 || $# -gt 2 ]]; then - echo "usage: run.sh [runs]" >&2 + echo "usage: run.sh [runs]" >&2 exit 2 fi ref=$1 @@ -22,8 +22,8 @@ fi work=$(mktemp -d) git clone https://github.com/Astn/JSON-RPC.NET.git "$work" -git -C "$work" fetch origin "$ref" -git -C "$work" checkout --detach FETCH_HEAD +# A branch, tag or full hash is fetched; anything else (a short hash) is resolved from the full clone. +git -C "$work" fetch origin "$ref" && git -C "$work" checkout --detach FETCH_HEAD || git -C "$work" checkout --detach "$ref" cd "$work" dotnet build -c Release TestServer_Console -nodeReuse:false dotnet run -c Release --no-build --project TestServer_Console -- --machine From 5856bf979c2ee7eac61baea11cbb2ba6eb59b9a5 Mon Sep 17 00:00:00 2001 From: Austin Harris Date: Sun, 27 Sep 2026 16:22:56 -0600 Subject: [PATCH 4/4] AUS-1011: Give the hf child process a UTF-8 environment in fetch.py On Windows the hf CLI wrote the job log with the console code page and failed on the harness's box-drawing characters before fetch.py saw a byte. --- benchmarks/hf/fetch.py | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/benchmarks/hf/fetch.py b/benchmarks/hf/fetch.py index cb39b8d..bfba228 100644 --- a/benchmarks/hf/fetch.py +++ b/benchmarks/hf/fetch.py @@ -1,6 +1,7 @@ """Fetch a Hugging Face Job's UTF-8 log and framed sweep JSON files.""" import argparse import json +import os import pathlib import re import subprocess @@ -15,8 +16,10 @@ def main(): parser.add_argument("out_dir", type=pathlib.Path) args = parser.parse_args() + # The hf CLI writes the log with the console's code page unless told otherwise; the harness prints box-drawing characters. + env = dict(os.environ, PYTHONIOENCODING="utf-8", PYTHONUTF8="1") result = subprocess.run(["hf", "jobs", "logs", args.job_id], stdout=subprocess.PIPE, - stderr=subprocess.PIPE, check=False) + stderr=subprocess.PIPE, check=False, env=env) if result.returncode: raise SystemExit(result.stderr.decode("utf-8", errors="replace")) log = result.stdout.decode("utf-8", errors="replace")