Faster store writes, a faster allocator, smaller binaries, and benchmarks

.github/RELEASE_NOTES.md

@@ -2,6 +2,18 @@
 
 Every artifact below is published with a `.sha256` beside it, so the download can be checked against a digest that was written by the same job that built it.
 
+### What's new in v0.3.1
+
+Faster, smaller, and measured.
+
+**Storing events is about seven times faster.** Events kept with `--store` are written in batches, one transaction each, instead of one transaction per event. Storing 100,000 events from a relay went from about 2,300 a second to about 16,800, each signature still checked, and a batch is still stored before any of it is printed.
+
+**Everything that allocates is faster.** deed now uses a general-purpose allocator instead of mapping pages for every allocation. Decoding a stream of npubs is about eight times faster, and verifying about a fifth faster.
+
+**The Linux downloads are less than half the size.** Release binaries are built without debug information. The Linux ones go from 12 MB to under 3 MB, and every download is now under 2 MB.
+
+**Benchmarks.** [BENCHMARKS.md](https://github.com/zig-nostr/deed/blob/main/BENCHMARKS.md) has the numbers, and `python3 bench/run.py` reproduces them on your machine.
+
 ### What's new in v0.3.0
 
 `publish` says what it published.

.github/workflows/release.yml

@@ -91,7 +91,7 @@ jobs:
             esac
 
             rm -rf "out-$target"
-            zig build -Dtarget="$target" -Doptimize=ReleaseSafe --prefix "out-$target"
+            zig build -Dtarget="$target" -Doptimize=ReleaseSafe -Dstrip=true --prefix "out-$target"
 
             bin="out-$target/bin/deed"
             [ -s "$bin" ] || { echo "$target produced no binary" >&2; exit 1; }

BENCHMARKS.md

@@ -0,0 +1,71 @@
+# Benchmarks
+
+What deed costs to run: how big it is, how fast it starts, how much memory it takes, and how fast it signs, verifies, stores and reads events. Every number here comes from [`bench/run.py`](bench/run.py), which you can run against your own build:
+
+```sh
+zig build -Doptimize=ReleaseSafe -Dstrip=true
+python3 bench/run.py zig-out/bin/deed
+```
+
+It needs python3 and [websocat](https://github.com/vi/websocat). Everything happens on your machine: the relay it talks to is [`bench/relay.py`](bench/relay.py) on 127.0.0.1, and nothing is sent anywhere else. Each timing is the best of several runs, because on a shared machine noise only ever adds time.
+
+Measured on an Apple M2 Pro with macOS 26.6, with deed 0.3.1 built as it is released (`ReleaseSafe`, stripped).
+
+## Size
+
+| Release | Binary | Download |
+| --- | --- | --- |
+| macOS, Apple Silicon | 2.3 MB | 1.6 MB |
+| macOS, Intel | 2.4 MB | 1.7 MB |
+| Linux, x86_64 | 2.7 MB | 1.8 MB |
+| Linux, aarch64 | 2.4 MB | 1.7 MB |
+
+The Linux binaries are statically linked, so that is everything they need.
+
+## Starting, and one event at a time
+
+| | |
+| --- | --- |
+| starting any process at all (`/usr/bin/true`), for scale | 1.56 ms |
+| `deed version` | 2.34 ms |
+| `deed key generate` | 2.37 ms |
+| `deed decode <npub>` | 2.41 ms |
+| `deed event`, signing one | 2.41 ms |
+| `deed verify`, one | 3.02 ms |
+| peak memory, `deed version` | 1.7 MB |
+
+deed's own share of a one-shot command is under a millisecond; the rest is the operating system starting a process. Verifying one event adds about 0.6 ms to that.
+
+## Streams
+
+| 10,000 records through stdin | |
+| --- | --- |
+| signing (`deed event -`) | 22,660 per second |
+| verifying (`deed verify`) | 33,270 per second |
+| decoding npubs (`deed decode`) | 586,718 per second |
+| peak memory, verifying 10,000 | 3.8 MB |
+
+## The local store
+
+100,000 signed events from 1,000 authors: a profile, a follow list and 98 notes each.
+
+| | |
+| --- | --- |
+| storing them from a loopback relay (`req --store`), each signature checked first | 16,864 per second |
+| the store file for them | 94 MB |
+| one event by id (`req --local -i`) | 3.25 ms |
+| one profile (`-a <pubkey> -k 0 -l 1`) | 3.30 ms |
+| one author's latest 50 notes | 3.47 ms |
+| the latest 500 notes (`-k 1 -l 500`) | 4.94 ms |
+| every note, 98,000 of them | 284 ms |
+
+The query times are the whole command, starting deed included, so a lookup costs about a millisecond more than `deed version` does. Events are written to the store in batches, in one transaction each, and a batch is stored before any of it is printed.
+
+## Relays, over loopback
+
+| | |
+| --- | --- |
+| `req` for 500 events | 44.5 ms, of which the test relay starting a Python process is about 20 |
+| `publish` 1,000 events, waiting for each one's OK | 6,884 per second |
+
+These leave the network out, so they measure deed and not the distance to a relay. Against a real relay, the round trip to it dominates.

README.md

@@ -19,7 +19,7 @@ macOS and Linux, Intel and ARM. It works out which build this machine wants, che
 The script is short and worth reading before you pipe anything into bash. If you would rather do it yourself:
 
 ```sh
-VERSION=0.3.0
+VERSION=0.3.1
 PLATFORM=macos-aarch64   # or macos-x86_64, linux-x86_64, linux-aarch64
 BASE=https://github.com/zig-nostr/deed/releases/download/v$VERSION
 
@@ -105,6 +105,10 @@ Scripts branch on these, so they are part of the interface and not free to drift
 | `2` | the command was not understood: unknown verb, unknown flag, missing argument. Nothing was attempted |
 | `141` | the reader on the other end of the pipe went away, as in `deed decode … \| head -1` |
 
+## How fast it is
+
+A one-shot command runs in about 2.3 ms and under 2 MB of memory. deed signs about 22,000 events a second and verifies about 33,000, stores 100,000 events from a relay at about 17,000 a second, and answers a lookup from that store in about 3 ms, start to finish. The binaries are 2.3 to 2.7 MB. [BENCHMARKS.md](BENCHMARKS.md) has the full set and how to reproduce every number.
+
 ## Build
 
 ```sh

bench/relay.py

@@ -0,0 +1,27 @@
+"""A relay for benchmarking deed, on loopback only.
+
+websocat runs one of these per connection and hands it each websocket message
+as a line. On REQ it sends every event in the corpus, then EOSE; on EVENT it
+answers OK true. It ignores the filter, which is why the benchmark asks for
+every kind the corpus holds.
+"""
+import json
+import sys
+
+corpus = sys.argv[1]
+out = sys.stdout
+for line in sys.stdin:
+    try:
+        msg = json.loads(line)
+    except ValueError:
+        continue
+    if msg[0] == "REQ":
+        sub = json.dumps(msg[1])
+        with open(corpus) as f:
+            for ev in f:
+                out.write('["EVENT",' + sub + "," + ev.rstrip("\n") + "]\n")
+        out.write(json.dumps(["EOSE", msg[1]]) + "\n")
+        out.flush()
+    elif msg[0] == "EVENT":
+        out.write(json.dumps(["OK", msg[1]["id"], True, ""]) + "\n")
+        out.flush()

bench/run.py

@@ -0,0 +1,149 @@
+"""Benchmarks for deed: startup, memory, bulk throughput, the local store,
+and relays over loopback.
+
+    python3 bench/run.py [path/to/deed]
+
+Needs python3 and websocat. Everything runs on this machine: the relay is
+bench/relay.py on 127.0.0.1, and nothing is sent anywhere else. Each timing is
+the best of several runs, because on a shared machine noise only ever adds.
+"""
+import json
+import os
+import shutil
+import statistics
+import subprocess
+import sys
+import tempfile
+import time
+
+DEED = os.path.abspath(sys.argv[1] if len(sys.argv) > 1 else "zig-out/bin/deed")
+HERE = os.path.dirname(os.path.abspath(__file__))
+AUTHORS = 1000
+NOTES_PER_AUTHOR = 98  # plus a profile and a follow list: 100,000 events in all
+PORTS = (47460, 47461)
+
+
+def run(args, data=None):
+    r = subprocess.run([DEED] + args, input=data, capture_output=True)
+    if r.returncode != 0:
+        sys.exit(f"deed {' '.join(args[:3])} failed: {r.stderr.decode()[:300]}")
+    return r.stdout
+
+
+def timed(argv, data=None, runs=5):
+    """Best and median wall time in milliseconds."""
+    ts = []
+    for _ in range(runs):
+        t = time.perf_counter()
+        r = subprocess.run(argv, input=data, stdout=subprocess.DEVNULL, stderr=subprocess.DEVNULL)
+        ts.append((time.perf_counter() - t) * 1000)
+        if r.returncode != 0:
+            sys.exit(f"{' '.join(argv[:3])} exited {r.returncode}")
+    return min(ts), statistics.median(ts)
+
+
+def peak_mb(args, data=None):
+    """Peak resident memory, from /usr/bin/time."""
+    flag = "-l" if sys.platform == "darwin" else "-v"
+    r = subprocess.run(["/usr/bin/time", flag, DEED] + args, input=data, stdout=subprocess.DEVNULL, stderr=subprocess.PIPE)
+    for line in r.stderr.decode().splitlines():
+        if "maximum resident set size" in line.lower():
+            n = int(line.split()[0] if sys.platform == "darwin" else line.split()[-1])
+            return n / 1048576 if sys.platform == "darwin" else n / 1024
+    return float("nan")
+
+
+def row(label, value):
+    print(f"| {label} | {value} |")
+
+
+def main():
+    work = tempfile.mkdtemp(prefix="deed-bench-")
+    relays = []
+    try:
+        print(f"deed: {DEED} ({run(['version']).decode().strip()}), {os.path.getsize(DEED):,} bytes\n")
+        print("| | |\n| --- | --- |")
+
+        key = run(["key", "generate"]).decode().strip()
+        npub = run(["key", "public", key]).decode().strip()
+        one = run(["event", "-c", "hello", "--sec", key]).decode().strip()
+        floor, _ = timed(["/usr/bin/true"], runs=200)
+        row("starting any process at all (`/usr/bin/true`)", f"{floor:.2f} ms")
+        for label, args in [
+            ("`deed version`", ["version"]),
+            ("`deed key generate`", ["key", "generate"]),
+            ("`deed decode <npub>`", ["decode", npub]),
+            ("`deed event` (sign one)", ["event", "-c", "hello", "--sec", key]),
+            ("`deed verify` (one)", ["verify", one]),
+        ]:
+            best, _ = timed([DEED] + args, runs=200)
+            row(label, f"{best:.2f} ms")
+        row("peak memory, `deed version`", f"{peak_mb(['version']):.1f} MB")
+
+        n = 10000
+        drafts = "".join(json.dumps({"kind": 1, "content": f"note {i}, a few words of ordinary length"}) + "\n" for i in range(n)).encode()
+        signed = run(["event", "-", "--sec", key], drafts)
+        npubs = ((npub + "\n") * n).encode()
+        for label, args, data in [("sign", ["event", "-", "--sec", key], drafts), ("verify", ["verify"], signed), ("decode", ["decode"], npubs)]:
+            best, _ = timed([DEED] + args, data)
+            row(f"{label} 10,000 through stdin", f"{n / best * 1000:,.0f} per second")
+        row("peak memory, verifying 10,000", f"{peak_mb(['verify'], signed):.1f} MB")
+
+        corpus = os.path.join(work, "corpus.jsonl")
+        with open(corpus, "wb") as f:
+            for a in range(AUTHORS):
+                k = run(["key", "generate"]).decode().strip()
+                d = [{"kind": 0, "content": json.dumps({"name": f"author {a}"}), "created_at": 1700000000 + a},
+                     {"kind": 3, "content": "", "created_at": 1700000001 + a}]
+                d += [{"kind": 1, "content": f"note {i} by author {a}, a few words of ordinary length", "created_at": 1700000000 + a * 100 + i} for i in range(NOTES_PER_AUTHOR)]
+                f.write(run(["event", "-", "--sec", k], "".join(json.dumps(x) + "\n" for x in d).encode()))
+        total = AUTHORS * (NOTES_PER_AUTHOR + 2)
+        with open(corpus) as f:
+            lines = f.readlines()
+        author = json.loads(lines[AUTHORS * 50])["pubkey"]
+        event_id = json.loads(lines[total // 2])["id"]
+        with open(os.path.join(work, "small.jsonl"), "w") as f:
+            f.writelines([l for l in lines if '"kind":1,' in l][:500])
+
+        websocat = shutil.which("websocat") or sys.exit("websocat is needed for the relay benchmarks")
+        for port, name in zip(PORTS, ("corpus.jsonl", "small.jsonl")):
+            relays.append(subprocess.Popen([websocat, "-t", f"ws-l:127.0.0.1:{port}", f"sh-c:exec python3 {HERE}/relay.py {work}/{name}"], stderr=subprocess.DEVNULL))
+        time.sleep(1)
+        big, small = (f"ws://127.0.0.1:{p}" for p in PORTS)
+
+        store = os.path.join(work, "store")
+        ingest = ["req", "--store", store, "-k", "0", "-k", "1", "-k", "3", "-l", str(total), "--timeout", "600000", big]
+        best = float("inf")
+        for _ in range(3):
+            for p in (store, store + "-lock"):
+                if os.path.exists(p):
+                    os.remove(p)
+            t = time.perf_counter()
+            run(ingest)
+            best = min(best, time.perf_counter() - t)
+        row(f"store {total:,} events from a loopback relay, each checked", f"{total / best:,.0f} per second")
+        row("store file for them", f"{os.path.getsize(store) / 1048576:.0f} MB")
+        local = ["req", "--store", store, "--local"]
+        for label, args in [
+            ("`--local`: one event by id", ["-i", event_id]),
+            ("`--local`: one profile", ["-a", author, "-k", "0", "-l", "1"]),
+            ("`--local`: one author's latest 50 notes", ["-a", author, "-k", "1", "-l", "50"]),
+            ("`--local`: latest 500 notes", ["-k", "1", "-l", "500"]),
+        ]:
+            best, _ = timed([DEED] + local + args, runs=30)
+            row(label, f"{best:.2f} ms")
+        best, _ = timed([DEED] + local + ["-k", "1", "-l", str(total)])
+        row(f"`--local`: every note, {AUTHORS * NOTES_PER_AUTHOR:,}", f"{best:.0f} ms")
+
+        best, _ = timed([DEED, "req", "-k", "1", "-l", "500", small], runs=20)
+        row("`req` 500 events from a loopback relay", f"{best:.1f} ms, of which the test relay starting Python is about 20")
+        pub = b"".join(signed.splitlines(keepends=True)[:1000])
+        best, _ = timed([DEED, "publish", big], pub, runs=3)
+        row("`publish` 1,000 events to a loopback relay, each OK awaited", f"{1000 / best * 1000:,.0f} per second")
+    finally:
+        for r in relays:
+            r.kill()
+        shutil.rmtree(work, ignore_errors=True)
+
+
+main()

build.zig

@@ -11,11 +11,16 @@ pub fn build(b: *std.Build) void {
         .optimize = optimize,
     });
 
+    // Release builds pass -Dstrip. Without it a Linux binary carries about
+    // nine megabytes of debug sections, three quarters of the file.
+    const strip = b.option(bool, "strip", "Leave debug information out of the binary");
+
     const exe_mod = b.createModule(.{
         .root_source_file = b.path("src/main.zig"),
         .target = target,
         .optimize = optimize,
         .link_libc = true,
+        .strip = strip,
     });
     exe_mod.addImport("nostr", nostr_dep.module("nostr"));
 

build.zig.zon

@@ -1,6 +1,6 @@
 .{
     .name = .deed,
-    .version = "0.3.0",
+    .version = "0.3.1",
     .fingerprint = 0x89498c2094a1a4a3,
     .minimum_zig_version = "0.16.0",
     .dependencies = .{
@@ -10,8 +10,8 @@
         // themselves later, and "whatever main happened to be that afternoon"
         // is not that.
         .nostr = .{
-            .url = "https://github.com/zig-nostr/nostr/archive/refs/tags/v0.14.5.tar.gz",
-            .hash = "nostr-0.14.5-CMyPzUgLCQBev0r22ht88wNHfIfc6vajpRq-hylCECfB",
+            .url = "https://github.com/zig-nostr/nostr/archive/refs/tags/v0.14.6.tar.gz",
+            .hash = "nostr-0.14.6-CMyPzdIdCQA3NHmWla4isas-_wBilj5IuVrSRCSL7eZ_",
         },
     },
     .paths = .{

src/main.zig

@@ -15,7 +15,7 @@ const cmd_publish = @import("cmd_publish.zig");
 const cmd_req = @import("cmd_req.zig");
 const cmd_verify = @import("cmd_verify.zig");
 
-pub const version = "0.3.0";
+pub const version = "0.3.1";
 
 const usage =
     \\deed: the nostr command line
@@ -49,7 +49,10 @@ const usage =
 ;
 
 pub fn main(init: std.process.Init) !void {
-    const gpa = std.heap.page_allocator;
+    // A general-purpose allocator, not `page_allocator`: that one maps pages
+    // for every allocation, so every small string was a system call, and
+    // decoding a stream of codes spent most of its time in mmap and munmap.
+    const gpa = std.heap.smp_allocator;
 
     var threaded = std.Io.Threaded.init(gpa, .{});
     defer threaded.deinit();