From 25c65e7fa6fd493baf6bd87ebce39d1406614566 Mon Sep 17 00:00:00 2001 From: Kacy Fortner Date: Wed, 29 Jul 2026 13:23:59 +0000 Subject: [PATCH] report median and p99 from the pith grpc client MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit the client printed an "average" computed as wall clock over total calls, which under eight-way concurrency divides one stream's worth of time across all eight — it read almost an order of magnitude better than the go and rust medians while measuring something else entirely. the comment blaming millisecond clock resolution predated the monotonic nanosecond clock. every call is now timed with mono_nanos, each worker pushes its latencies into a shared per-worker list, and the merged sorted set yields the same nearest-rank median and p99 the go client prints, in the same duration format. the doc table is refreshed from a three-round interleaved rerun with all three clients on identical metrics: pith 7476 calls/sec at 954us median against go's 14731 at 471us and rust's 12005 at 591us on the 16-byte payload. workers hand latencies back through a shared list handle rather than a task result, because extracting an awaited result with a list payload miscompiles both ways today — unwrap_or emits an unresolvable call and .ok trips the ir contract's field-offset check. that is filed separately; the comment in the client says why the shape is what it is. --- bench/grpc/pith/client.pith | 82 ++++++++++++++++++++++++++----------- docs/performance.md | 28 +++++++------ 2 files changed, 74 insertions(+), 36 deletions(-) diff --git a/bench/grpc/pith/client.pith b/bench/grpc/pith/client.pith index 0ad648f2..ae50dcb3 100644 --- a/bench/grpc/pith/client.pith +++ b/bench/grpc/pith/client.pith @@ -1,12 +1,12 @@ # the pith grpc benchmark client: warm up, then time many unary echo calls over -# one channel and print calls/sec. parameters come from the environment so the -# runner can drive it the same way it drives the go and rust clients: +# one channel and print calls/sec plus per-call median and p99. parameters come +# from the environment so the runner can drive it the same way it drives the go +# and rust clients: # PITH_GRPC_SIZE, PITH_GRPC_CALLS, PITH_GRPC_WARMUP, PITH_GRPC_CONC, PITH_GRPC_CA # -# pith has only millisecond wall-clock resolution, so the batch (thousands of -# calls, seconds long) gives the throughput and an average latency — the fair -# common metric across all three clients. per-call percentiles are left to the -# go and rust clients. +# each call is timed with the monotonic nanosecond clock and every worker hands +# its latencies back; the merged, sorted list gives the same median and p99 the +# go and rust clients report, so the three rows read alike. import std.net.http2.connection as http2 import std.net.grpc as grpc @@ -16,6 +16,7 @@ import std.bytes as bytes import std.time as time import std.os as os import std.concurrent as concurrent +import std.algo as algo fn env_str(name: String, fallback: String) -> String: value := os.get_env(name).unwrap_or(fallback) @@ -57,39 +58,73 @@ fn echo_request(payload: Bytes) -> Bytes: w.write_bytes(1, payload) catch false return w.bytes() -fn run_serial(ch: grpc.Conn, method: String, request: Bytes, calls: Int): - mut i := 0 - while i < calls: - ch.unary(method, request) catch bytes.empty() - i = i + 1 - -fn worker(ch: grpc.Conn, method: String, request: Bytes, count: Int) -> Int: +# time each call, pushing the latency of every call into `lat` (a shared list +# handle created by the caller — task results with list payloads are avoided on +# purpose, the handle is the simpler contract). +fn timed_batch(ch: grpc.Conn, method: String, request: Bytes, count: Int, lat: List[Int]) -> Int: mut i := 0 while i < count: + t0 := time.mono_nanos() ch.unary(method, request) catch bytes.empty() + lat.push(time.mono_nanos() - t0) i = i + 1 return count # each worker gets its OWN connection from the pool (round-robin) and keeps its -# calls on that one connection's pipeline, so the pool spreads load across cores. -fn run_concurrent(pool: grpc.PoolConn, method: String, request: Bytes, calls: Int, conc: Int): +# calls on that one connection's pipeline, so the pool spreads load across +# cores. every worker's latencies come back through its task result and are +# merged for the percentile report. +fn run_concurrent(pool: grpc.PoolConn, method: String, request: Bytes, calls: Int, conc: Int, merged: List[Int]): per := calls / conc mut tasks := [] + mut buckets: List[List[Int]] := [] mut w := 0 while w < conc: c := pool.at(w % pool.size()) - tasks.push(spawn worker(c, method, request, per)) + bucket: List[Int] := [] + buckets.push(bucket) + tasks.push(spawn timed_batch(c, method, request, per, bucket)) w = w + 1 for t in tasks: await t - -fn report(size: Int, conc: Int, calls: Int, elapsed_ms: Int): + for bucket in buckets: + for v in bucket: + merged.push(v) + +# the value at `pct` percent of the way through a sorted list, matching the +# nearest-rank convention the go client uses. +fn percentile_ns(sorted: List[Int], pct: Int) -> Int: + if sorted.len() == 0: + return 0 + mut rank := (sorted.len() * pct) / 100 + if rank >= sorted.len(): + rank = sorted.len() - 1 + return sorted[rank] + +# nanoseconds as the go client prints durations: microseconds below one +# millisecond, fractional milliseconds above. the micro sign is built from its +# utf-8 byte pair, the same way other non-ascii output in this repo is. +fn fmt_ns(ns: Int) -> String: + micro := chr(194) + chr(181) + if ns < 1000000: + return (ns / 1000).to_string() + micro + "s" + whole := ns / 1000000 + frac := (ns % 1000000) / 1000 + if frac < 10: + return whole.to_string() + ".00" + frac.to_string() + "ms" + if frac < 100: + return whole.to_string() + ".0" + frac.to_string() + "ms" + return whole.to_string() + "." + frac.to_string() + "ms" + +fn report(size: Int, conc: Int, calls: Int, elapsed_ms: Int, latencies: List[Int]): mut ms := elapsed_ms if ms <= 0: ms = 1 throughput := (calls * 1000) / ms - avg_us := (ms * 1000) / calls - print("pith size={size} conc={conc} calls={calls} avg={avg_us}us {throughput} calls/sec") + sorted := algo.sort(latencies) + med := fmt_ns(percentile_ns(sorted, 50)) + p99 := fmt_ns(percentile_ns(sorted, 99)) + print("pith size={size} conc={conc} calls={calls} median={med} p99={p99} {throughput} calls/sec") fn main(): size := env_int("PITH_GRPC_SIZE", 16) @@ -123,11 +158,12 @@ fn main(): w = w + 1 start := time.now() + latencies: List[Int] := [] if conc <= 1: - run_serial(ch.at(0), method, request, calls) + timed_batch(ch.at(0), method, request, calls, latencies) else: - run_concurrent(ch, method, request, calls, conc) + run_concurrent(ch, method, request, calls, conc, latencies) elapsed := time.now() - start - report(size, conc, calls, elapsed) + report(size, conc, calls, elapsed, latencies) ch.close() diff --git a/docs/performance.md b/docs/performance.md index a7004d8f..7b91def4 100644 --- a/docs/performance.md +++ b/docs/performance.md @@ -24,7 +24,7 @@ rows are the green backend, which is the default on linux; rows marked | services and compute | pith | go | rust | zig | |---|---:|---:|---:|---:| | catalog workload, 200k requests | **~114 ms** | ~436 ms | ~80 ms | — | -| grpc unary echo, conc=8, 16 B | 8326 calls/s | 14795 | 11788 | — | +| grpc unary echo, conc=8, 16 B | 7476 calls/s | 14731 | 12005 | — | | http server under wrk, 30 s | 8079 req/s, rss flat (+4 kb) | 28453 req/s (+6.1 mb) | — | — | | event_ledger, 200k events | 618 ms (1.28x go) | 481 ms | 117 ms | 137 ms | | std_pipeline, 50k records | 576 ms (1.63x go) | 352 ms | 177 ms | — | @@ -227,18 +227,20 @@ binaries. | payload, conc=8 | pith | go | rust | |---|---:|---:|---:| -| 16 B, calls/sec | 8326 | **14795** | 11788 | -| 16 B, latency | 120 µs avg | 465 µs median, 1.7 ms p99 | 593 µs median, 2.3 ms p99 | -| 1 KiB, calls/sec | 6216 | **11339** | 9557 | -| 1 KiB, latency | 160 µs avg | 600 µs median, 2.9 ms p99 | 712 µs median, 3.3 ms p99 | - -pith sits at ~55% of go and ~65-70% of rust on throughput. the latency -rows are not directly comparable — the pith client reports a plain -average where go and rust report median and p99 — but the shape is -consistent: pith's per-call time is low and its ceiling is the two-core -box splitting the client, the server, and the connection's single reader -task. teaching the pith client to report percentiles is a small follow-up -that would make the row honest to compare. +| 16 B, calls/sec | 7476 | **14731** | 12005 | +| 16 B, median / p99 | 954 µs / 2.9 ms | 471 µs / 2.0 ms | 591 µs / 2.3 ms | +| 1 KiB, calls/sec | 7598 | **12366** | 9545 | +| 1 KiB, median / p99 | 957 µs / 2.5 ms | 555 µs / 2.5 ms | 717 µs / 3.3 ms | + +all three clients now report the same metrics: per-call median and p99 +from the full sorted latency set, timed with each language's monotonic +clock. pith sits at ~50-60% of go and ~60-80% of rust on throughput, with +a per-call median about 2x go's — one connection means one reader task, +and the two-core box splits it against the server and seven sibling +callers. the earlier revision of this table printed a pith "average" +computed as wall-clock over total calls, which under eight-way concurrency +flattered pith by nearly an order of magnitude; the percentile reporting +replaced it. | 16 B, conc=8 | calls/sec | ctx-switches/call | cpu | |---|---|---|---|