Backend environment for match hosting for lance.blue
arena PERFORMANCE.md
46 kB

Performance #

A match is a Swing application streamed to the browser: every input crosses the network to us-east-1, and every pixel comes back as WebSocket frames. Latency and frame bytes are therefore the product, and both have been measured end to end - Chrome performance traces correlate each input through WebSocket send, receive, and canvas draw, while Suramadu's per-frame statistics (enabled below) land in CloudWatch for the server-side split. All numbers are production measurements from a residential connection in Boston. The correlation was hand work; suramadu/web/perf.js now records the same four points in the browser when a match is opened with ?perf=1 - see TODO.md for what remains unverified. Net effect so far: median downpress-to-pixels roughly halved (~158ms to ~100ms), input-to-socket worst case cut from 134ms to under 5ms at p90, and the latency tail (p90) down from ~470ms to ~330ms under heavier play.

What this series is worth, measured while somebody is playing #

Every figure below is a click - mousedown/mouseup, never a coalesced mousemove - against a live firing phase on a quiet machine, driven by scripts/perf/latency-pilot.py, 156 clicks an arm. Two independent runs of the same comparison:

before, run 1 before, run 2 after, run 1 after, run 2
p50 67.0ms 72.4ms 55.0ms 54.8ms
p90 127.7ms 118.9ms 84.8ms 107.2ms
p99 150.8ms 152.4ms 132.8ms 143.9ms
bytes received 2,046,929 2,091,815 1,129,511 1,095,660

About 21% off the median, 22% off the p90, and 46% fewer bytes, and the two numbers that matter most repeat almost exactly - 55.0 against 54.8 for the median, and the byte totals within 3% of each other.

Most of it is one change. The javaagent on its own, same image, same interaction, only ARENA_LAZY_PNG differing:

p50 p90 p99 bytes
off (stock Suramadu) 77.2ms 136.3ms 173.8ms 1,070,692
on 59.5ms 78.7ms 127.2ms 1,062,369

Identical bytes, a fifth off the median and over 40% off the p90 - because the encode it removes was CPU on the send path, and CPU on the send path is what the tail is made of. The bytes come from elsewhere in the series: the chatterbox blink, the webFolder, the summary encode.

None of this was visible from the deployment-phase board every earlier figure in this file was taken on. That board is idle enough to make CPU look free, which is how the PNG level got shipped and reverted in the same afternoon.

Shipped #

Change Where Result
Match task 1 to 2 vCPU, 8GB infra 618b73c Three JVMs starved one core; the client JVM pegged 100% until the watchdog killed it.
TCP_NODELAY on both proxy legs headquarters 4628fbd Small WebSocket messages no longer wait on Nagle. send-to-receive median 114ms to 63ms.
Per-frame stats + GC logs to stdout 47487a3 The measurement enabler. Upstream's bundled log4j2 config routes stats to a dead logger, so a custom config was required, not optional.
Send keyboard input immediately (suramadu patch 0001) 1365089 The client held keys behind a 100ms timer. keydown-to-socket 33-134ms down to ~21ms.
EntityImage headless fix (megamek patch 0005) 21c80d5 The class died at static init in headless JVMs, breaking camo and re-running image work per entity sync.
Flush coalesced mouse input every 20ms (suramadu patch 0002) eef0e92 Hover/drag paid up to 100ms before the server saw the mouse. Input-to-socket p90 is now under 5ms.
DirectDraw image cache 128 to 16384 entries bab83d6 8de5814 MegaMek's hex/sprite working set far exceeds 128; evicted images re-send as full PNGs. 4096 first, then 16384: -17%/-23% bytes.
Paint dispatcher tick 33ms to 16ms e6ba5cc A repaint costs ~1.5 ticks of latency; halving the tick took ~25ms off the median frame.
lance.blue skin: 1008px background tile, no board border 0d96fa1 63898c3 e61fc91 Branding, plus a cache-friendly large tile and a reclaimed 45px border band.
Skip pointless FoV hex-cache clears (megamek patch 0006) 207dec8 Selecting a unit cleared the whole hex composite cache, recomposited the board, stalled the EDT, and tripped Suramadu's cache-reset timeout. Biggest tail win: total p90 ~440ms to ~330ms.
Marshal sprite image callbacks to the EDT (megamek patch 0007) 207dec8 Closes a verified capture race (Suramadu encodes live buffers during drawImage). Correctness fix; the visible tearing has a second, unresolved cause.
Disable move animation and chat auto-slide 207dec8 400e4ac Repaint churn: hex-by-hex movement and a 50Hz slide animation each streamed frames for nothing.
Headless accelerated-image fallback (megamek patch 0008) 351eb0b createAcceleratedImage(Image) returned null headless, erasing base images mid-build and aborting SENDING_ENTITIES — silent bot force-ID divergence. Correctness fix; negligible CPU. Not yet confirmed in a container.
Turn FoV darkening off 33518d6 The shading is baked into the hex composites, so what patch 0006 kept was a full recomposite of the board on every real selection change, plus a LosEffects per hex out to 60. Off, checkFoVHexImageCacheClear returns immediately. Unmeasured, but it is the same work 0006 measured, on the path 0006 left in place.
Client ack-on-receive (suramadu patch 0003) 1a1e5c7 The client acked a frame only after painting it, keeping the render inside the server's send loop; acking on receive lets the next frame travel while this one paints.
Precompress the webFolder (suramadu/precompress-web.sh) this commit Suramadu serves a .br or .gz sibling if one is already there and compresses nothing on the fly, and ours had none - so the theme, the report and the flare UI all went out uncompressed. 106,031B of JS/CSS/HTML/SVG becomes 29,369B brotli, on every cold load. Written in the suramadu stage, so neither compressor reaches the shipped image.
Stop repainting for an invisible cursor (megamek patch 0016) this commit ChatterBoxOverlay started an ungated 500ms Timer in its constructor that toggled a text cursor and called refreshDisplayables() for the life of the session. The cursor is only drawn when the chatter box is active, so on a quiet match it repainted every displayable to change nothing anybody could see - and on a streamed client each refresh is a frame. Captured off the wire: 5,980 bytes every 500ms, consecutive frames 99.8% identical, 12,480 B/s. After the guard, a quiet client sends nothing at all - 0 frames in the same 12 second window.
Lazy-encode ImageConst PNG (javaagent, instrument/lazy-png-agent/) 2609c49, on by default in this commit The constructor PNG-encoded every image and DrawConstantPool then discarded it on a hash hit, so deferring to toMessage() means a cache hit never encodes at all. A/B on one human seat, same build, only ARENA_LAZY_PNG differing: png/deflate samples 737 on the EDT to 0, EDT running samples 1648 to 740, and the first interaction of a match 361ms to 49ms - most of the warm-up cliff is this. ARENA_LAZY_PNG=0 restores stock behaviour for bisecting.

The host JVM spends more CPU compiling than playing #

A ctimer profile of the match host over a whole bench-4v4, bucketed by frame:

share of host samples
JIT (C1 and C2 compiling) 52.9%
class load and verify 10.6%
GC 7.4%

That is a task with two vCPUs, shared with Princess and with the frame path, spending over half of the host's CPU on the compiler. -XX:TieredStopAtLevel=1 (C1 only, no C2) on the host, same build and scenario, only that flag differing:

stock C1 only
host samples over the run 3,038 1,421
of which JIT 54.3% 16.7%
match ready 23s 21s

So the compiler really is the cost, and removing C2 halves what the host burns. It is measured, and it loses. The same two arms, driven against a played seat with the pilot that clears its ring buffer:

stock C1 only
host samples 1,750 1,250
of which JIT 53.8% 18.3%
warm inputToPaint p50 54ms 75ms at best, 216-264ms in two of three runs
inputToPaint p90 70-132ms 97-469ms
match ready 15s 18s

Two of the five C1 runs paired no loops at all, which is what an input the server does not answer inside the window looks like. Freeing a vCPU of compiler time buys less than worse codegen costs, and Princess is what runs that code.

Retested against a live firing phase, and it is worse than this section found. The figures above came from a board stalled in deployment; driven at a real firing phase the same flag takes p50 from 67.3ms to 133.0ms and p90 from 141.1ms to 1,538.4ms. The host-CPU saving is real and irrelevant - see "Do not do these" above. ARENA_HOST_JIT_ARGS stays as a knob for the next person with a different idea about it - -XX:CICompilerCount and a tiered threshold are both untried - but the obvious version of this does not work.

AppCDS was the first idea here and the profile ruled it out: it removes class loading and verification, which is the 10.6%, and does nothing about the 52.9% on JDK 21.

The cold cliff is an empty image cache, not warm-up #

Driven against a played seat, the first pilot run of a match reads p50 839ms input-to-paint and the ones after it read ~54ms. Frame sizes from those same runs say what the difference is:

run frames total p50 frame p90 frame largest
1 (p50 839ms) 13 881KB 6,057B 168,529B 473,246B
2 (p50 55ms) 22 139KB 6,127B 6,150B 22,511B
5 (p50 54ms) 60 388KB 6,141B 6,156B 22,418B

The median frame is the same in all three, about 6.1KB. Nothing is uniformly slower when a match is cold, and the run that felt worst shipped the fewest frames. The whole difference is a handful of very large ones - a p90 twenty-seven times the warm figure, and a single 473KB frame.

So it is not JIT, and with the javaagent on it is not the encode either. It is the board arriving. Those three frames total 881KB, which is what this file already records a full board repaint costing, and they land in a window of 3.6 seconds starting 26 seconds into the session - which is when auto-ready fires, the match leaves the lounge and the board is painted for the first time. The largest of them followed no input at all, and the other two arrived 620 and 682ms after the last one, so nothing the player did provoked them.

It does not recur. The same pan a few seconds later costs 139KB across 22 frames, and a later run ships sixty frames for 388KB with nothing over 50KB in either. One board, once.

Which puts it at the worst possible moment rather than a random one: the whole board transfers exactly as the match becomes playable, and a player's first interactions queue behind it. At 25 Mbps that is most of a second of link with nothing else able to cross it. Two ways at it, neither tried - move the transfer earlier, into the lounge where the player is already waiting and the link is idle, or make the composites smaller, since EncoderBase.getRGBABytes says they are 32-bit RGBA on art that would palettize. The second is also the only lever in this file that acts on the ~330ms tail and the cold cliff at the same time.

Pre-compiling at build time: what is and is not possible #

The host spends more CPU compiling MegaMek than doing anything else, and the obvious question is whether a Docker build can do that work once instead of every match. Not the compiling. Temurin 21 has SharedArchiveFile, ArchiveClassesAtExit and AutoCreateSharedArchive and no AOTCache or AOTMode: CDS archives classes that are loaded and linked, never compiled code. Persisting JIT output needs the JDK 24/25 AOT cache, OpenJ9, or a native image, and none of those is this JVM. The C1 experiment says the compiler's output is worth having - taking C2 away made everything far worse - so what is wanted is the code without the compiling, which is exactly what 21 cannot do.

The class loading half is real, though, and there is something worth knowing: this image ships no CDS archive at all. jlink does not write one and the Dockerfile did not ask, so a host start loaded 0 of 4,827 classes from an archive. It also makes AppCDS impossible - -XX:ArchiveClassesAtExit refuses with "unsupported when base CDS archive is not loaded".

Building both (a -Xshare:dump after jlink, then a training run of arena.MatchHost against a scenario name that does not resolve, which loads the whole class graph on its way to failing):

classes from the archive host JVM start, median of 5
as shipped 0 of 4,827 5,864ms
base archive 1,240 of 4,815 6,177ms
base + AppCDS 4,580 of 4,761 4,838ms

And it does not move a match. Interleaved against a build without it, four rounds each: 24, 24, 30, 29s without, 28, 25, 25, 28s with - the same 26.5s median. The archive is loaded (-Xlog:cds=warning is silent in a real container), the second saved is real, and readiness is not waiting on it. It waits on Suramadu's port, on MegaMek's data, on the bots being built.

Not shipped: 30MB of image for a second that nobody is waiting on.

And the client cannot have one at all, which is worth writing down because this page previously pointed at it as the obvious next move. Suramadu launches the client with --patch-module java.desktop=<modpatch> to install WebToolkit11, and that flag disables CDS in both directions:

$ java --patch-module java.desktop=<modpatch> -XX:ArchiveClassesAtExit=b.jsa -version
Error occurred during initialization of VM
Cannot use the following option when dumping the shared archive: --patch-module

$ java --patch-module java.desktop=<modpatch> -Xshare:on -version
warning: CDS is disabled when the --patch-module option is specified.

So the client runs with CDS off entirely - not merely missing an app archive, but without the default base archive an ordinary JVM gets for free. Removing the flag means baking the modpatch into a jlinked java.desktop, and it would buy little: class loading is 7.3 thread-seconds of a ~35s client startup. The client's -cp is only the war (main.Main) in any case; MegaMek is loaded by Suramadu's own classloader from -Dwebswing.classPath, so it was never in an app archive's reach.

Cold start: 35s to a board, and it is not the CPU #

A production cold start measured 1m42s from "click deploy" to a visible mech. The task lifecycle accounts for the first part - 18.0s Fargate provisioning, 15.7s image pull, 6.1s container start, 16.9s init to host-ready - and then 31.7s from the client JVM starting to the board being on screen. That last number reproduces locally on bench-4v4: 32-46s, measured as the arrival of the board's bytes rather than of a first paint, because the first paints are Suramadu's loading UI and land at ~2s while the board is still 30s away. scripts/perf/startup.py is that measurement.

Two things it is not:

board on screen
2 vCPU 32.8s, 43.9s
4 vCPU 33.8s, 31.8s
ARENA_AUTO_READY=20 32.8s, 43.9s
ARENA_AUTO_READY=3 37.3s, 46.1s

Not CPU-bound, so a larger Fargate task buys nothing - worth knowing before anyone reaches for sizing.rs. Not the auto-ready timer either, so it is not an artefact of how the bench scenario starts.

What it is: -Xlog:class+load shows 13,993 classes loading continuously from 0.01s to 34.9s, with only 6s sitting in gaps longer than 0.3s. Nothing is blocked on a timer; it is one long serial chain. Neither side is busy while it happens - the client's connection thread is parked in a socket read and the host does 22.8 non-idle thread-seconds across the whole match - which is why a wall-clock profile reads as idle and hides the cost.

The first 15s is 8,207 classes of Suramadu's own dependency stack, before MegaMek loads anything: log4j2 ~1,341, two Jackson stacks ~885 (both com.fasterxml.jackson and tools.jackson), BCEL 344, Tyrus, protobuf, JAXB, snakeyaml. MegaMek's own classes do not start until ~15s (megamek.common.weapons), and its unit cache and image loading are only ~2.5s of the whole thing.

The BCEL is the mechanism rather than a passenger. org/webswing/classloader/SwingClassloader.modifyClass, in suramadu-app-services.jar, parses and rewrites every application class through BCEL as it loads, to redirect a fixed set of calls (RedirectedMethods.getSystemClassLoader, setOut, listRoots, the JSObject accessors). There is no cache and no skip-list in it: the rewrite is unconditional, per class, every boot. Caching those rewritten bytes - warmed at image build, so a player's boot reads them instead of recomputing them - is the open lead. It is not yet sized: BCEL sampled 2.5s of wall time, not 15s, so the prize may be 2-4s rather than the whole first third, and sizing it is the first step rather than the patch.

Reading the pilot: clear the buffer, and only trust discrete input #

Two traps in scripts/perf/latency-pilot.py, both of which have already cost a comparison each.

perf.js records into a ring buffer that starts when the page opens, so a second run against the same match reduces everything the first one saw as well. Left alone this reads as a stable result - identical summaries to the decimal from the third run onwards - which is exactly what a good measurement looks like. The pilot now clears it on attach, and a run whose record counts climb between iterations is not measuring what it thinks.

And the client acks every frame it receives, so sends outnumber inputs about eight to one and the send paired with an input is usually an ack. That puts a ~33ms cadence floor inside every sendToRecv, and it wrecks coalesced input entirely: mousemove reads a p90 of 129ms against 55ms for a click on the same run. Quote clicks - mousedown and mouseup are never coalesced.

Do not do these: three ways to trade a player's tail for nothing #

Three separate changes looked like wins, were measured, and are wrong. They fail for one reason, and it is worth stating before the list: each adds CPU or frames to a path that is contended while somebody is playing, and each was first measured on a board that was not being played. A match stalled in the deployment phase has an idle server, which makes CPU look free. It is not.

don't it buys it costs measured against
arena.pngLevel above 2 42% fewer bytes p50 55→91ms, p90 85→470ms, p99 133→1,547ms live firing phase
ARENA_DRAW_DELAY_MS=8 ~13ms of median, on an idle board p50 67→98ms, p90 141→670ms live firing phase
ARENA_HOST_JIT_ARGS=-XX:TieredStopAtLevel=1 29% less host CPU, JIT 54%→17% p50 67→133ms, p90 141→1,538ms live firing phase

The dispatcher tick is the one to be most careful about, because on a stalled board it reads as a win - 13.8ms off the median at eight units, reproducibly

  • and under play the sign flips. Anybody re-deriving that number on a quiet board will find the same encouraging figure and ship it.

The knobs are all still there. They are how these were measured and how somebody takes the trade somewhere the CPU genuinely is idle. What is not there is a default that assumes it.

The general rule this file should keep: measure against a match somebody is playing. --spectate gives real turns with no human to stall on, and the bench scenarios now pre-place their units so a human seat reaches movement and firing instead of sitting in deployment forever. Every latency figure taken before that was a cursor moving over an idle board, and three changes were justified on it.

Investigated, not shipped #

Idea Outcome
Raise ddMaxConstCacheSize Wrong knob: it is an id-space boundary and per-frame sanity cap, not a memory limit.
Server-side two frames in flight Rejected: requires a jar-patch build pipeline for one Suramadu class. Revisit only if transport-bound again.
Ship fonts to the browser (#@@ fontconfig entries) Named physical fonts (Noto Sans, symbols) rasterize server-side; shippable but a polish item, not latency.
Repaint the board by hex instead of in full Measured and rejected — see below. Do not retry without a new argument.
-XX:G1HeapRegionSize=8m on the client JVM Measured and rejected — see below.
Rendering at a lower canvas resolution No effect on bytes — see "What the wire actually carries".
Enabling WebSocket compression Already on. Jetty negotiates permessage-deflate today; nothing to enable.
Turning MegaMek's terrain shadows off Measured: 18.5% off the first board paint. Not shipped, because it is a change to how the map looks and that is not ours to make silently - see below.

What the wire actually carries #

Measured 2026-08-09 by wrapping WebSocket in the page before the Suramadu bundle loads, and reading the container's own eth0 counters for the wire side. Three things were assumed and are now known.

Compression is already on. The socket negotiates permessage-deflate, so anything measured in the browser as event.data is the decompressed size. The ratio is only 1.61× — wire is 62% of app-layer bytes — because the payload is mostly PNG, which does not recompress. There is no compression win left here.

The client's own draw dominates, not the server's. From Suramadu's stats over a scripted burst: latencyServerRendering median 1ms, p90 2ms; latencyClientRendering median 13-15ms, p90 17-21ms; total latency median 17-18ms. On a LAN. In us-east-1 add ~20ms RTT and the transfer time for the frame, which for a full board repaint (~860KB app-layer, ~530KB wire) is 43ms at 100 Mbps and 171ms at 25 Mbps. That is the shape of the ~330ms p90 tail.

Resolution does not change bytes. DirectDraw ships vector draw instructions plus image constants at their natural size, and the browser scales them, so the canvas backing store can double without the server sending more. Measured with a matched protocol: 2.56MB of load traffic at a 2× canvas against 2.53MB at 1×, and an identical 61,161 bytes for a repaint at both. An earlier 38% "win" here was an artefact of comparing a cold first session against a warm reload; the matched comparison shows nothing.

What a smaller canvas does buy is client CPU: latencyClientRendering median 15ms → 13ms, p90 21ms → 17ms. Worth having, not worth much against a 20ms RTT.

The frontend's getDpr() is Math.ceil(window.devicePixelRatio) || 1, so a 1.25 or 1.5 DPR display - a 125%-scaled laptop, which is most of them - renders at 2x, which is 2.56x the pixels the display can show. An earlier version of this section called that a bug worth fixing. It is not a bug, and the ceil is load-bearing.

dpr is threaded through the whole DirectDraw path - withDpr, identityTransform, calculateBias, and the image buffer sizing in drawWebImage:

c.width === l.width*h && c.height === l.height*h || (c.width = l.width*h, ...)

canvas.width is an integer setter. With a fractional dpr that product is fractional, the browser floors it, the equality can never hold, and the buffer is reallocated on every draw. Math.ceil is what keeps it integral.

So the real choice is integral and coarse: render at 1x and let the browser upscale to 1.25 (blurrier, 2.56x cheaper), or render at 2x and downscale (sharper, what we do). That is a quality decision, not a defect, and it is not ours to make silently - it changes how the game looks. Math.round would take 1.25 displays down to 1x and leave 1.5 and above at 2x, if the sharpness is ever judged not worth the pixels.

Worth less than it looks, too: the 15ms -> 13ms above is client CPU, and once the paint ack stops waiting for the render (patch 0003) that time is no longer inside the server's send loop at all.

G1HeapRegionSize=8m: measured, rejected #

The client JVM runs G1 with a 2GB heap, which picks 1MB regions, so any allocation over 512KB is "humongous" and goes straight to old gen. Board repaint buffers reach 860KB-1.6MB, so large frames were provoking G1 Humongous Allocation cycles — 13 of 63 pauses in a 150s burst. Raising the region size to 8m moves the humongous threshold to 4MB, which should have made those ordinary allocations.

It does, and it is still not worth it. Identical 150s scripted burst, ~450 messages each:

pauses total pause median p90 max of which humongous
1M regions (default) 100 742ms 5.5ms 14.5ms 49ms 13
8m regions 128 887ms 4.4ms 14.5ms 60ms 6

Humongous cycles halved, but evacuation pauses rose 42% and total pause time rose 20%, with a worse maximum. p90 was unchanged. Larger regions trade one kind of collection for more of another. Do not retry without a different argument — 4m was not tried, and might sit differently, but the effect being chased is worth about 10ms of pause per 150s either way.

How a match scales with units on the board #

Every render measurement before 2026-08-09 used a 2-unit training scenario. data/scenarios/lance-blue/ now carries three that vary only unit count and board area, and scripts/perf/stats.py reports percentiles from the container log. The same scripted pan sweep on each:

scenario units total bytes median frame p90 frame p90 latency
bench-2v2 4 19.04MB 13,080 20,191 57ms
bench-4v4 8 19.15MB 18,162 197,239 68ms
bench-4x4 16 19.23MB 18,297 298,858 82ms

Total bytes move 1% across four times the units, because the sweep reveals the same board area either way. The p90 frame grows 15x and p90 latency 44%. Any measurement that reports a median will say these three perform alike.

Princess, not rendering: where the CPU goes at 16 units #

The obvious reading of the table above is that more units cost more to draw. That is not what the container says. Per-process CPU inside the task, sampled over a window, 16 units, the production 2-vCPU shape:

phase match host (Princess) client JVM (rendering) total of 200%
human's turn, player interacting 0% 40% 33%
bot turns 155% - 149%

Princess is idle while a human is deciding, and takes about 1.55 of the 2 cores once it is thinking - for 16 units across three bot factions. Rendering wants roughly 0.4 of a core. Together that is 195% of a 200% budget.

So the latency tail at 16 units is a contention problem, not a drawing one, and it only bites when a player interacts while bots are thinking - which is exactly what happens in a 4-player match, where someone is always mid-turn. It also means the 2-vCPU task is sized for the small end: fine at 4 units, at its ceiling at 16.

Two consequences worth taking seriously before a 4-player match ships:

  • CPU per match should scale with units, not be fixed. See infra.
  • Anything that makes rendering cheaper buys nothing during a bot turn, because rendering is not what is holding the core. Bytes still matter - they are network, not CPU - but EDT-side render optimisation is aimed at the 0.4.

Did our own tuning become a regression at scale? #

Everything in the Shipped table was measured on a 2-unit training scenario, where the task never runs out of CPU. Two of those changes make the client do work more often, and re-measuring them at 16 units - where the task is saturated - shows one of them has inverted.

webswing.drawDelayMs 33 -> 16 halved the paint dispatcher tick. On bench-4x4, 2 vCPU, a player panning while Princess takes its turns:

16ms (shipped) 33ms (stock)
input latency median 36ms 40ms
input latency p90 146ms 114ms
input latency max 663ms 602ms
p90 frame 257,637 215,462
total container CPU 195% of 200% 190% of 200%

The 16ms tick still wins the median, by about 4ms, and loses the p90 by about 32ms. That is the trade nobody made deliberately: it was chosen against a 2-unit scenario where the extra ticks were free, and a saturated task charges for them.

And then it un-inverts. The table above was taken with loopback packet compression still on - with the host JVM spending ~13% of a contended 2 vCPU gzipping packets to clients inside its own container. With that removed, the same comparison on a combined branch, identical protocol, only the tick differing:

16ms 33ms
input latency median 19ms 37ms
input latency p90 64ms 119ms
client render p90 28ms 44ms

The direction reverses and 16ms wins both ends by roughly 2x. The extra ticks were never the problem; they were unaffordable only because a third of the host's CPU was going somewhere useless.

So: keep drawDelayMs=16, take the gzip fix, and do not build the adaptive tick this section originally argued for - it would now make things worse. The general lesson is the one worth keeping: a knob tuned against a saturated system is measuring the saturation, not the knob.

The same argument applies, untested, to Suramadu patch 0002 (mouse flush 100ms -> 20ms): five times the input flushes, each able to provoke a repaint. Combined with the doubled tick that is up to ten times stock's repaint opportunities during continuous mouse movement. Worth measuring the same way before assuming it is free.

MegaMek patch 0007 is a third, milder suspect: it marshals sprite imageUpdate callbacks onto the EDT, which is correct - it closes a capture race - but adds work to the thread that is already the contended one at 16 units.

Shadows: measured, and somebody else's call #

GUIP.getShadowMap() gates terrain and building shadows, and they are composited into each hex image rather than drawn per frame. So they are not a CPU cost worth chasing - they are a byte cost. A shadow is a soft gradient, which is the one thing a PNG of flat tile art compresses badly, and every hex carrying one is a larger image constant the first time the browser is sent it.

Same build, same scenario, one preference differing, measuring the burst where the board first reaches the browser:

first board paint frames in the burst
shadows on (today) 881,018B 13
shadows off 718,264B 11

18.5%, and it applies to every later board repaint as well, so it is one of the few levers that touches both the cold cliff and the ~330ms tail. At 25 Mbps it is worth about 50ms of the second the board currently takes to arrive.

It is not shipped and this file is not the place it gets decided. Shadows are how the map looks, and the rule this repository already applies to the DPR choice applies here: a quality decision, not a defect, and not ours to make silently. <preference name="ShadowMap" value="false"/> in megamek/clientsettings.xml.template is the whole change if it is wanted, and before/after screenshots belong in that pull request rather than this table.

The dispatcher tick below 16ms: the same trade, one octave down #

Once the board has been sent, a warm frame is 6KB and the wire is about 2ms of a ~50ms sendToRecv. The largest server-side term left is the paint dispatcher tick: a change waits for the next one, so it is worth about a tick and a half per repaint. The section above settled 33 against 16 and never went lower.

ARENA_DRAW_DELAY_MS makes that a knob rather than a rebuild. Twelve pilot runs an arm, one human seat, warm runs pooled, at both unit counts:

8 units, tick 16 8 units, tick 8 16 units, tick 16 16 units, tick 8
input-to-paint p50 57.8ms 44.0ms 55.5ms 45.1ms
sendToRecv p50 50.0ms 36.9ms 48.9ms 37.8ms
input-to-paint p90 114.0ms 107.3ms 116.9ms 130.9ms

The median win is real, reproducible and mechanical: 13.8ms at eight units and 10.4ms at sixteen, essentially all of it in sendToRecv, which is where the tick lives - and 13ms is what halving a 16ms tick should be worth on the tick-and-a-half model. An earlier two-run pass suggested 27ms; that was noise, and this is the figure.

The p90 does not survive the unit count, and that is the same inversion this file already records for 33 against 16: better median, worse tail, appearing only once the task is busy enough to charge for the extra ticks. There it went away when a third of the host's CPU stopped being spent gzipping loopback packets. So the reading is not "8 is wrong" but "8 is what 16 was" - it wants the next host CPU waster removed before it can be taken, and the host is still spending 53% of its samples in the compiler.

Not shipped: 16 stays the default. A tail that gets worse at the unit count four-player matches run at is not a trade to make for a median, and the knob is here so it can be retaken cheaply when the host has room.

Retested against a live firing phase, and the median win does not survive. Every figure above came from a deployment-phase board. Under play the same knob reads p50 67.3ms to 97.6ms and p90 141.1ms to 670.2ms - it loses both ends, and the encouraging 13.8ms median is an artefact of measuring an idle server. See "Do not do these" above.

There is no second gzip-sized waster on the host #

The loopback-gzip fix was found by reading a host profile and seeing 13% in Deflater/Inflater. The obvious next move is to look for another one, and a ctimer profile of a 16-unit match says there is not one: the largest single non-JIT leaf is 1.54%. Half the host's samples are the compiler and the other half is a long flat tail with no lump in it.

The nearest thing to a lump is zlib at about 5-7%, and it is three unrelated things rather than one:

share of the zlib samples
SendPacket.<init> - the server compressing outbound packets ~37%
ObjectInputStream - deserialisation ~36%
Resource.getBytes, ZipFile - class loading out of the jars ~24%

A patch was written and measured against the first reading of that - disable compression on a client connection whose host is loopback, which is the client-side half the existing fix does not cover, since compression is negotiated per packet and each direction turns it off where it is produced. It made no difference (5.5% against 7.0%, which is noise), and the breakdown above is why: the client half is not where the bytes are. It was dropped rather than shipped.

What the table does leave open is SendPacket.<init>. arena.MatchHost already sets setCompression(false) on every server connection as it appears, and the server is still compressing outbound packets - so either that loop misses a connection, or the flag is read somewhere it does not reach. Worth an hour from somebody; it is the one lump left and it is in code we already patch.

The client is dirty while a cursor is moving, not while a game is playing #

An earlier version of this section said a playing client streams continuously and the tick multiplies it. The match was not playing. Every measurement in this file that used ARENA_AUTO_READY ended no-victory-at-exit at round 0: auto-ready gets the seat out of the lounge, nothing takes the human's deployment turn, and the game sits there. No unit ever moved and nothing ever fired.

What that changes: the ~6.2KB every 34ms was the pilot's own cursor, not the game. Left alone on the same board, the client sends 18 frames in 35 seconds and ten of them are under 300 bytes - the board arriving, then near-silence. Frames follow input.

So the tick still multiplies throughput, but only while somebody is moving the mouse, and that is a smaller and more bursty share of a match than "permanently dirty" implied. The p90 inversion at sixteen units is still real and still measured; the explanation for it is now narrower.

What survives untouched is everything about bytes, because those are properties of what crosses the wire rather than of what provoked it: the 881KB first board paint, the 97 image constants inside it, the zlib level they are encoded at, the webFolder, and the chatterbox blink.

Nothing in this file has measured a match being played. The latency figures are a deployment-phase board with a cursor on it - a real thing a player does, and the cheapest thing they do. Movement plotting and firing ask the server for LOS and pathfinding and have never been timed. Suramadu's own stats from the same runs put latency at p50 45ms and p90 87ms, which corroborates the click figures independently, and they are measuring the same undemanding state.

What a match being played actually costs: almost nothing #

A spectated bench-4v4 runs to real turns - Princess takes every faction, so nothing waits on a human and the game reaches round 3 rather than stalling at deployment. Captured off the wire for 57 seconds of that, with no input at all:

frames 17
bytes 104,407
rate 1,837 B/s
median gap between frames 1,990ms
frame sizes mostly 46-636B; one 6KB; one 90,703B

The game is nearly free. Units moving, weapons firing, phases turning over - a few hundred bytes every couple of seconds, and a single large frame where something changed the whole board. The link is idle almost all the time.

Two things follow, and they point the remaining work in one direction.

The blinking chat cursor removed by megamek patch 0016 was 12,480 B/s, which is nearly seven times what the entire game costs. That is the shape of the wins available here: not the simulation, but things repainting for no reason.

And what is left is where it always was - the 881KB first board paint, which is one payment at the worst possible moment, and whatever the player's own pointer provokes. Gameplay is not a cost worth optimising, so raising the zlib level on image constants and shrinking that first paint are the levers that matter, and both act on bytes rather than on the simulation.

What an expensive action costs: the tail roughly doubles #

The bench scenarios now carry deployment hexes, so a match reaches movement and firing instead of sitting in the deployment phase waiting for a human who never clicks. Driven against a live firing phase - weapons panel open, LOS and to-hit being computed, the firing arc drawn over the board:

n p50 p90 max
mousemove 56 52.0ms 105.6ms 191.3ms
mousedown 56 50.5ms 103.5ms 189.4ms
mouseup 56 48.7ms 101.5ms 187.3ms

43 of 56 clicks drew a reply over 4KB. On the deployment-phase board every earlier measurement used, 3 of 52 did - which is how much of the expensive path those runs were missing, and why their tail looked better than it is.

The median barely moves, about 50ms either way. The tail is what real work costs: p90 goes from ~55ms on an idle board to ~104ms while the server is answering for line of sight, and the worst case reaches 191ms. That is the number a player feels as the game being sticky, and it is the one this file had never measured.

Taken with the section above - a match being played costs 1,837 B/s when nobody touches it - the picture is that neither the simulation nor the idle client is where a player's time goes. It goes on the first board paint, and on the server answering the pointer while it has real work to do.

Raising the PNG level: measured under play, and reverted #

ImageServiceImpl encodes every image constant with ZPNG.encode(image, channels, 2) - the trailing literal is the zlib level, hardcoded to 2. Pulling the 97 image constants a real board's first paint puts on the wire and re-encoding them through ZPNG itself: 832,900B at level 2, 669,372B at 6, 647,472B at 9. Level 2 reproduces the sent bytes exactly, so the reading is exact rather than inferred.

It was shipped at 6 on the reasoning that the client has CPU to spare. That was measured on a board sitting in the deployment phase with nothing happening, and it is wrong under play. The same image and the same interaction against a live firing phase, only arena.pngLevel differing:

p50 p90 p99 bytes
level 2 (stock) 55.0ms 84.8ms 132.8ms 1,129,511B
level 6 90.8ms 469.5ms 1,547.2ms 658,037B

42% fewer bytes for +454% on the p90 and +1064% on the p99. zlib on the send path is not free while the server is also working out line of sight, and the tail is what a player feels. Reverted to 2; arena.pngLevel still raises it for somewhere the CPU genuinely is idle.

The lesson is the method rather than the number. This was measured, shipped, and wrong inside an hour, and what caught it was measuring a match that was actually being played instead of one stalled in deployment.

Repainting the board by hex: measured, rejected #

The most expensive thing a click can do is make the board repaint. Splitting 120 input-to-pixel loops from a production trace by reply size:

socket to frame, p50
no board repaint (n=20, under 1KB back) 26.5ms
full board repaint (n=81, over 10KB back) 132ms

So a board repaint costs ~105ms, and 81 of 120 interactions paid it. MegaMek ends most interactions in a bare boardPanel.repaint(), which dirties the whole panel, so every visible hex composite is redrawn and PNG-encoded on the EDT to show a change that usually touches one or two hexes. Repainting only the changed area is the obvious answer, and it does not work.

Two patches were written to test it: one logging each repaint's clip rectangle as a share of the viewport, one narrowing the two call sites where the changed area was already known - boardChangedHex, which drops exactly seven hex composites, and clearMovementData, which erases a path whose sprites have bounds. Measured over a match played to round 2's physical phase, with the narrowing applied:

n=100  mean=100%  <=5%:0   <=100%:100
n=500  mean=96%   <=5%:11  <=10%:6  <=100%:480

480 of 500 repaints still dirtied the whole viewport, and the 17 narrow ones are as likely to be moveCursor, which was already narrow upstream, as anything the patch did.

The reason is structural. Swing's RepaintManager keeps one rectangle per component and unions all damage into it, and the board is a single component. A tooltip, a unit-display refresh or any overlay repainting in the same event pulls the union back out to the full panel, however precisely each call describes its own damage. Narrowing two of the fifteen bare repaint() calls cannot beat that, and narrowing all fifteen would not either: most of them - board-wide changes, ECM and label updates, scrolling, phase transitions - dirty everything for real reasons.

The ~105ms is still real. It is just not reachable by describing damage more precisely, so what is left are the levers that reduce the work rather than the area: fewer pixels (capping the canvas) and cheaper pixels (the background tile, then the per-draw PNG encode).

Profiling #

Everything above was reasoned out of MegaMek and Suramadu source and out of aggregate latency. No flame graph has ever been taken in this container, so the attribution inside a single frame is inference, not measurement.

async-profiler ships in the image and stays dormant unless the task sets ARENA_PROFILE=1. Then the client JVM gets a wall-clock profile - the EDT question is a latency question, and a blocked EDT costs a player what a busy one does - and the match host gets a ctimer CPU profile, which answers whether Princess's pathfinding takes cores away from rendering on a 2-vCPU task. ctimer rather than cpu because cpu means perf_events, and Docker's default seccomp profile blocks perf_event_open; a profiler that silently collects nothing is worse than one that is slightly coarser everywhere. Both write collapsed stacks, which finalize uploads with the rest of the match artifacts.

The same exit path now reduces Suramadu's per-session stats lines into an n/mean/p50/p90/max table per metric, which is the per-layer split - server render, client render, network, ping, EDT blocked - that the sections above had to reason around.

Two questions this exists to settle: whether the client EDT is dominated by PNG encoding in Suramadu's ImageConst, by MegaMek hex compositing, or by GC; and whether Princess steals CPU from rendering while a player is watching. Neither has been run.

Open #

  • Intermittent frame tearing: MegaMek's paint paths are audited clean; the evidence points at Suramadu's frame extraction racing paintComponent, or a remaining poisoned-constant vector. Needs a Suramadu-side fix; see TODO.md.
  • Full-repaint frames still reach ~1MB, the floor of the latency tail. Not in warm play. 617 frames pooled from sixteen measurement windows across five builds: p50 6,150B, p90 6,271B, p99 22,511B, largest 38,873B. Nothing approaches a megabyte once the board has been sent once, and that holds with the lazy-png javaagent off as well as on, so it is not the agent's doing - a warm repaint ships draw instructions referencing constants the browser already holds, not the constants. The ~860KB figure is the first board paint (see the cold-cliff section), which was misattributed to repaints. What follows from it: at 6KB a frame the wire is about 2ms at 25 Mbps, so a warm p90 of 70-132ms is server and round trip, not bytes. Measured against a 20ms netem link rather than a residential one, so it says what the protocol does, not what a lossy link does to it.
  • Load-time batch: ~2s of JS boot before first paint. The assets themselves are cached and compressed already; what is left is small, and TODO.md has the detail.