mirror of
https://github.com/vitorpamplona/amethyst.git
synced 2026-10-06 03:38:23 +00:00
perf(nip77): direct-build NEG-MSG wire frames (~2.5–2.8× serialization)
The server's per-round reconcile spends a large slice turning the ~1MB hex reconcile frame into wire JSON: the generic (Jackson) serializer wraps the hex string in a value node and scans every char for JSON escapes a [0-9a-f] payload can never contain, then re-copies. NegMsgMessage.toJson() now builds ["NEG-MSG","<sub>","<hex>"] directly — no node tree, no escape scan of the hex. Fast path fires only for escape-free printable-ASCII subIds (what the JSON encoder emits verbatim); exotic subIds fall back to the generic serializer, so output is byte-identical. RelaySession.send routes through message.toJson() (default unchanged for every other message type). Measured (toJson + UTF-8, per frame): 64KiB 2.5×, 250KiB 2.6×, 500KiB (strfry cap) 2.8× — ~2.5ms saved per NEG-MSG, ~35ms over a 14-round reconcile. Correctness: a subId battery asserts byte-identity with the generic path, and GeodeVsStrfryNegentropySyncTest (real strfry) reconciles against the fast-built frames. Also records the ingest-latency candidate as measured-not-worth-it: the IngestQueue pipeline overhead is only ~0.17ms p50, <10% of the ~2.4ms receipt→queryable gap — that gap lives in the REQ-visibility path, not the writer. Full write-up in quartz/plans/2026-07-04-sync-serialization-and-ingest-latency.md. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_012EZeWww5TJnzBZKPoc6mvU
This commit is contained in:
Claude
@@ -0,0 +1,60 @@
|
||||
# Two more relayBench gaps: NEG-MSG serialization (fixed) + ingest latency (measured, not worth it)
|
||||
|
||||
Follow-up to the 1M relayBench run and the NIP-77 diagnosis
|
||||
(`2026-07-04-negentropy-reconcile-profiling.md`). Both were measured in
|
||||
isolation first so the fix could be judged on the delta.
|
||||
|
||||
## NEG-MSG wire serialization — **fixed** (~2.5–2.8×)
|
||||
|
||||
The server's per-round reconcile JFR put a large slice in serialization: a
|
||||
reconcile frame is `Hex.encode`d to a ~1 MB hex string, then the outgoing
|
||||
`NegMsgMessage` was turned into wire JSON by the generic (Jackson)
|
||||
serializer, which wraps the giant hex string in a value node and **scans
|
||||
every char for JSON escapes** a `[0-9a-f]` payload can never contain, then
|
||||
re-copies.
|
||||
|
||||
`NegMsgMessage.toJson()` now builds `["NEG-MSG","<sub>","<hex>"]` directly —
|
||||
no node tree, no escape scan of the hex. The fast path fires only when the
|
||||
client-chosen `subId` is escape-free printable ASCII (the bytes the JSON
|
||||
encoder emits verbatim); any exotic subId (quotes, control chars, non-ASCII)
|
||||
falls back to the generic serializer, so output is **byte-identical**.
|
||||
`RelaySession.send` now routes through `message.toJson()` (default is
|
||||
unchanged for every other message type).
|
||||
|
||||
Measured (`NegMsgSerializationBenchmark`, toJson + UTF-8, per frame):
|
||||
|
||||
| frame | generic | fast | speedup |
|
||||
|---|---:|---:|---:|
|
||||
| 64 KiB | 0.47 ms | 0.19 ms | 2.5× |
|
||||
| 250 KiB | 1.97 ms | 0.76 ms | 2.6× |
|
||||
| 500 KiB (strfry cap) | 3.87 ms | 1.37 ms | 2.8× |
|
||||
|
||||
At the 500 KB frame cap that's ~2.5 ms saved per NEG-MSG, ~35 ms over a
|
||||
14-round reconcile — server-side, on top of the (library-side) prefix-sum
|
||||
fingerprint work. Correctness: a subId battery asserts byte-identity with
|
||||
the generic path, and the `GeodeVsStrfryNegentropySyncTest` interop test
|
||||
(real strfry) reconciles against the fast-built frames.
|
||||
|
||||
## Receipt➜queryable ingest latency — **measured, not worth fixing**
|
||||
|
||||
Hypothesis: geode's group-commit `IngestQueue` (two channel handoffs,
|
||||
submit→verifier→writer) adds latency for a single event on an idle relay,
|
||||
explaining the 1M gap (geode 4.68 ms vs strfry 2.32 ms p50).
|
||||
|
||||
`IngestLatencyBenchmark` timed `submit→onComplete` (fires after COMMIT =
|
||||
queryable) vs a direct `batchInsert`:
|
||||
|
||||
| path | p50 | p90 | p99 |
|
||||
|---|---:|---:|---:|
|
||||
| IngestQueue (submit→OK) | 0.21 ms | 0.31 ms | 0.50 ms |
|
||||
| direct batchInsert | 0.05 ms | 0.09 ms | 0.17 ms |
|
||||
| **pipeline overhead** | **0.17 ms** | | |
|
||||
|
||||
The whole ingest trip is ~0.2 ms — the pipeline overhead (~0.17 ms) is <10%
|
||||
of the ~2.4 ms gap. A single-event fast path in the (carefully-tuned) writer
|
||||
can't close it. **The gap is in the cross-connection REQ-visibility/poll
|
||||
path, not ingest** — the probe publishes on one connection and hammer-polls
|
||||
`REQ {ids:[id]}` on another, so it's dominated by websocket round-trips +
|
||||
how fast a committed row surfaces to a concurrent reader, not the write. A
|
||||
real fix needs that path profiled; the writer is not the lever. Benchmark
|
||||
kept as the evidence.
|
||||
+4
-1
@@ -120,7 +120,10 @@ class RelaySession(
|
||||
|
||||
fun send(message: Message) {
|
||||
try {
|
||||
onSend(OptimizedJsonMapper.toJson(message))
|
||||
// message.toJson() defaults to OptimizedJsonMapper.toJson(this) for
|
||||
// every type; NegMsgMessage overrides it with a direct-build wire
|
||||
// path (identical output, ~2× faster on big reconcile frames).
|
||||
onSend(message.toJson())
|
||||
} catch (e: Exception) {
|
||||
Log.w("ClientSession") { "Failed to send to ${e.message}" }
|
||||
}
|
||||
|
||||
+37
@@ -20,6 +20,7 @@
|
||||
*/
|
||||
package com.vitorpamplona.quartz.nip77Negentropy
|
||||
|
||||
import com.vitorpamplona.quartz.nip01Core.core.OptimizedJsonMapper
|
||||
import com.vitorpamplona.quartz.nip01Core.relay.commands.toClient.Message
|
||||
|
||||
class NegMsgMessage(
|
||||
@@ -28,7 +29,43 @@ class NegMsgMessage(
|
||||
) : Message {
|
||||
override fun label() = LABEL
|
||||
|
||||
/**
|
||||
* Wire form is `["NEG-MSG","<subId>","<hex>"]`. The `<hex>` payload is a
|
||||
* reconciliation frame that can be ~1 MB and is *always* lowercase hex
|
||||
* (`Hex.encode`), so it never needs JSON escaping. The generic serializer
|
||||
* still wraps it in a value node and scans every char for escapes it can
|
||||
* never find, then re-copies — profiling put that at a large slice of the
|
||||
* server's per-round reconcile cost. Build the string directly instead,
|
||||
* skipping the scan and the intermediate nodes (measured ~2× faster at the
|
||||
* 500 KB frame cap).
|
||||
*
|
||||
* The fast path only fires when [subId] is plain printable ASCII with no
|
||||
* `"`/`\` — exactly the bytes the JSON encoder would emit verbatim — so
|
||||
* the output is byte-identical to the generic path. Any exotic subId
|
||||
* (control chars, quotes, non-ASCII) falls back to it.
|
||||
*/
|
||||
override fun toJson(): String {
|
||||
if (!isEscapeFreeAscii(subId)) return OptimizedJsonMapper.toJson(this)
|
||||
return buildString(message.length + subId.length + 16) {
|
||||
append("[\"")
|
||||
append(LABEL)
|
||||
append("\",\"")
|
||||
append(subId)
|
||||
append("\",\"")
|
||||
append(message)
|
||||
append("\"]")
|
||||
}
|
||||
}
|
||||
|
||||
companion object {
|
||||
const val LABEL = "NEG-MSG"
|
||||
|
||||
/** True when every char is printable ASCII (0x20–0x7e) and not `"`/`\`. */
|
||||
private fun isEscapeFreeAscii(s: String): Boolean {
|
||||
for (c in s) {
|
||||
if (c < ' ' || c > '~' || c == '"' || c == '\\') return false
|
||||
}
|
||||
return true
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
+8
@@ -45,6 +45,14 @@ import kotlin.test.Test
|
||||
* `store.batchInsert(listOf(e))` — the delta is exactly the pipeline's
|
||||
* coroutine-handoff overhead, the thing a single-event fast path would save.
|
||||
*
|
||||
* **Verdict (measured): the pipeline is not the bottleneck.** The overhead
|
||||
* came out at ~0.17 ms p50 (queue 0.21 ms vs direct 0.05 ms) — the whole
|
||||
* ingest trip is ~0.2 ms, far under the ~2.4 ms receipt➜queryable gap the 1M
|
||||
* run showed (geode 4.68 vs strfry 2.32 ms). So a single-event fast path in
|
||||
* [IngestQueue] can close <10 % of the gap; it isn't worth the complexity.
|
||||
* The gap lives in the cross-connection REQ-visibility/poll path, not the
|
||||
* writer — a separate investigation. This benchmark stays as the evidence.
|
||||
*
|
||||
* Prints percentiles; no speed assertion (container-noisy).
|
||||
*/
|
||||
class IngestLatencyBenchmark {
|
||||
|
||||
+47
-57
@@ -20,58 +20,26 @@
|
||||
*/
|
||||
package com.vitorpamplona.quartz.nip01Core.relay.prodbench
|
||||
|
||||
import com.vitorpamplona.quartz.nip01Core.core.OptimizedJsonMapper
|
||||
import com.vitorpamplona.quartz.nip77Negentropy.NegMsgMessage
|
||||
import kotlin.test.Test
|
||||
import kotlin.test.assertEquals
|
||||
|
||||
/**
|
||||
* Isolates the per-round NEG-MSG serialization tax that geode's server-path
|
||||
* JFR attributed ~40% of reconcile time to: a reconcile produces a binary
|
||||
* frame, `Hex.encode`s it to a ~1 MB hex String, then the outgoing [Message]
|
||||
* is turned into wire JSON by [com.vitorpamplona.quartz.nip01Core.kotlinSerialization.MessageKSerializer],
|
||||
* which builds a `JsonElement` tree (wrapping the giant hex string in a
|
||||
* `JsonPrimitive`) and re-serializes it — scanning every hex char for JSON
|
||||
* escapes that a `[0-9a-f]` payload can never contain — before Ktor UTF-8
|
||||
* encodes it to the socket.
|
||||
* Measures the NEG-MSG wire-serialization fix and guards its correctness.
|
||||
* geode's server-path JFR attributed a large slice of per-round reconcile
|
||||
* time to turning the reconcile frame into wire JSON: `Hex.encode` → the
|
||||
* generic (Jackson) [com.vitorpamplona.quartz.nip01Core.core.OptimizedJsonMapper]
|
||||
* serializer, which wraps the ~1 MB hex string in a value node and scans
|
||||
* every char for JSON escapes a `[0-9a-f]` payload can never contain.
|
||||
*
|
||||
* The wire is trivially `["NEG-MSG","<sub>","<hex>"]`, so a direct
|
||||
* `StringBuilder` skips the tree. This measures the current `toJson()` path
|
||||
* against that direct build (both followed by the UTF-8 encode a websocket
|
||||
* text frame pays), at realistic NEG-MSG sizes, and asserts they produce
|
||||
* byte-identical wire output.
|
||||
* [NegMsgMessage.toJson] now builds `["NEG-MSG","<sub>","<hex>"]` directly
|
||||
* (fast path for escape-free ASCII subIds; generic fallback otherwise).
|
||||
* This asserts the fast path is **byte-identical** to the generic path
|
||||
* across a battery of subIds — including exotic ones that must hit the
|
||||
* fallback — and times the two at realistic frame sizes.
|
||||
*/
|
||||
class NegMsgSerializationBenchmark {
|
||||
/** Direct wire build — `["NEG-MSG","<sub>","<hex>"]`, hex needs no escaping. */
|
||||
private fun directWire(
|
||||
subId: String,
|
||||
hex: String,
|
||||
): String =
|
||||
buildString(hex.length + subId.length + 16) {
|
||||
append("[\"NEG-MSG\",")
|
||||
append(jsonString(subId)) // client-chosen subId: escape defensively
|
||||
append(',')
|
||||
append('"')
|
||||
append(hex) // pure hex, no escaping possible
|
||||
append("\"]")
|
||||
}
|
||||
|
||||
/** Minimal JSON string encoder for the (short, usually-safe) subId. */
|
||||
private fun jsonString(s: String): String =
|
||||
buildString(s.length + 2) {
|
||||
append('"')
|
||||
for (c in s) {
|
||||
when (c) {
|
||||
'"' -> append("\\\"")
|
||||
'\\' -> append("\\\\")
|
||||
'\n' -> append("\\n")
|
||||
'\r' -> append("\\r")
|
||||
'\t' -> append("\\t")
|
||||
else -> if (c < ' ') append("\\u%04x".format(c.code)) else append(c)
|
||||
}
|
||||
}
|
||||
append('"')
|
||||
}
|
||||
|
||||
private fun hexPayload(rawBytes: Int): String {
|
||||
val chars = "0123456789abcdef"
|
||||
val sb = StringBuilder(rawBytes * 2)
|
||||
@@ -83,37 +51,59 @@ class NegMsgSerializationBenchmark {
|
||||
return sb.toString()
|
||||
}
|
||||
|
||||
@Test
|
||||
fun fastPathIsByteIdenticalToGeneric() {
|
||||
val hex = hexPayload(1024)
|
||||
val subIds =
|
||||
listOf(
|
||||
"bench-sync",
|
||||
"sub_123",
|
||||
"a".repeat(64),
|
||||
"", // empty
|
||||
"with\"quote", // → fallback
|
||||
"with\\backslash", // → fallback
|
||||
"tab\there", // → fallback
|
||||
"new\nline", // → fallback
|
||||
"unicode-é中", // non-ASCII → fallback
|
||||
"ctrlchar", // → fallback
|
||||
)
|
||||
for (sub in subIds) {
|
||||
val msg = NegMsgMessage(sub, hex)
|
||||
assertEquals(
|
||||
OptimizedJsonMapper.toJson(msg),
|
||||
msg.toJson(),
|
||||
"toJson() must match the generic serializer for subId=<$sub>",
|
||||
)
|
||||
}
|
||||
}
|
||||
|
||||
private fun bench(
|
||||
label: String,
|
||||
rawFrameBytes: Int,
|
||||
) {
|
||||
val subId = "bench-sync"
|
||||
val hex = hexPayload(rawFrameBytes)
|
||||
val msg = NegMsgMessage(subId, hex)
|
||||
|
||||
// Correctness: direct build must equal the serializer's wire output.
|
||||
assertEquals(msg.toJson(), directWire(subId, hex), "wire mismatch for $label")
|
||||
val msg = NegMsgMessage("bench-sync", hex)
|
||||
|
||||
val warmup = 200
|
||||
val runs = 500
|
||||
var sink = 0
|
||||
repeat(warmup) { sink = sink xor msg.toJson().length xor OptimizedJsonMapper.toJson(msg).length }
|
||||
|
||||
repeat(warmup) { sink = sink xor msg.toJson().length xor directWire(subId, hex).length }
|
||||
|
||||
// Include the UTF-8 encode a websocket text frame pays either way.
|
||||
val t0 = System.nanoTime()
|
||||
repeat(runs) { sink = sink xor msg.toJson().encodeToByteArray().size }
|
||||
val curMs = (System.nanoTime() - t0) / 1e6 / runs
|
||||
repeat(runs) { sink = sink xor OptimizedJsonMapper.toJson(msg).encodeToByteArray().size }
|
||||
val genMs = (System.nanoTime() - t0) / 1e6 / runs
|
||||
|
||||
val t1 = System.nanoTime()
|
||||
repeat(runs) { sink = sink xor directWire(subId, hex).encodeToByteArray().size }
|
||||
repeat(runs) { sink = sink xor msg.toJson().encodeToByteArray().size }
|
||||
val fastMs = (System.nanoTime() - t1) / 1e6 / runs
|
||||
|
||||
println(" %-18s cur %6.3f ms direct %6.3f ms %.1f× (sink=%d)".format(label, curMs, fastMs, curMs / fastMs, sink and 1))
|
||||
println(" %-16s generic %6.3f ms fast %6.3f ms %.1f× (sink=%d)".format(label, genMs, fastMs, genMs / fastMs, sink and 1))
|
||||
}
|
||||
|
||||
@Test
|
||||
fun negMsgWireSerialization() {
|
||||
println("─ NegMsgSerializationBenchmark: toJson()+utf8 vs direct build+utf8 ─")
|
||||
fun negMsgWireSerializationSpeedup() {
|
||||
println("─ NegMsgSerializationBenchmark: generic vs fast toJson()+utf8 ─")
|
||||
bench("64 KiB frame", 64 * 1024)
|
||||
bench("250 KiB frame", 250 * 1024)
|
||||
bench("500 KiB frame", 500 * 1024) // strfry's frame cap
|
||||
|
||||
Reference in New Issue
Block a user