M1-04C

# M1-04C: server + bot status lines from the 10-minute soak (logs/test-output/M1-04C-03.log, 2224 lines); per-connection join/leave lines dropped, [zone] status kept every 30 s
bots FAIL: 1000/1000 joined, 0 disconnects, loop p50 17.80 p99 1685.84 max 1685.84 ms (cpu/tick mean 4.51 p99 20.04 ms; phase means ingest 6.42 tick 4.38 build 9.73 hand-off 10.21 pool wait 2.31 ms; worker cpu/tick 7.86 ms; slow ticks 7575), skipped 11883 dropped ticks 1754, down mean 2419 p95 8259 max 8444 B/s/bot, rtt p50 42.4 p99 683.0 ms, memory drift -4.27% (rss mean 291 MiB), load 358.28 410.79 340.55 -> 251.60 273.62 299.28
  failed: loopP99WithinTarget
  failed: ticksDroppedUnder1Percent
[bots] 1000 bots -> ws://127.0.0.1:62325 on 4 workers: stepped ramp 100 -> 250 -> 500 -> 1000 (30 s a step: connects over the first half, holds the second), hold 600 s (load average 358.28 410.79 340.55)
[zone] t= 30.0s tick=601 clients=101 tick p50=0.74 ms p99=5.38 ms max=11.24 ms sent=47520 skipped=0 KB/s/client≈1.21
[bots] t= 30.0s connected=100 down≈855 B/s/bot rtt p99 52.0 ms rss 35 MiB disconnects=0
[zone] t= 60.0s tick=1201 clients=250 tick p50=1.26 ms p99=11.87 ms max=20.11 ms sent=181731 skipped=0 KB/s/client≈1.72
[bots] t= 60.0s connected=250 down≈1388 B/s/bot rtt p99 52.5 ms rss 79 MiB disconnects=0
[zone] t= 90.0s tick=1801 clients=500 tick p50=1.93 ms p99=14.35 ms max=29.13 ms sent=457866 skipped=0 KB/s/client≈2.59
[bots] t= 90.0s connected=500 down≈1993 B/s/bot rtt p99 54.5 ms rss 152 MiB disconnects=0
[zone] t=120.0s tick=2399 clients=1000 tick p50=2.79 ms p99=44.99 ms max=221.23 ms sent=1007975 skipped=0 KB/s/client≈3.79
[bots] t=120.0s connected=1000 down≈3262 B/s/bot rtt p99 54.0 ms rss 298 MiB disconnects=0
[zone] t=150.0s tick=2999 clients=1000 tick p50=3.92 ms p99=51.62 ms max=221.23 ms sent=1637980 skipped=0 KB/s/client≈3.34
[bots] t=150.0s connected=1000 down≈3110 B/s/bot rtt p99 66.0 ms rss 298 MiB disconnects=0
[zone] t=180.0s tick=3599 clients=1000 tick p50=7.75 ms p99=60.66 ms max=221.23 ms sent=2267977 skipped=0 KB/s/client≈3.18
[bots] t=180.0s connected=1000 down≈2928 B/s/bot rtt p99 83.5 ms rss 298 MiB disconnects=0
[zone] t=210.0s tick=4199 clients=1000 tick p50=10.72 ms p99=59.10 ms max=221.23 ms sent=2897976 skipped=0 KB/s/client≈3.10
[bots] t=210.0s connected=1000 down≈2743 B/s/bot rtt p99 86.0 ms rss 298 MiB disconnects=0
[bots] t=240.0s connected=1000 down≈2852 B/s/bot rtt p99 86.5 ms rss 297 MiB disconnects=0
[zone] t=240.1s tick=4800 clients=1000 tick p50=11.87 ms p99=56.95 ms max=221.23 ms sent=3529015 skipped=0 KB/s/client≈3.04
[bots] t=270.0s connected=1000 down≈2871 B/s/bot rtt p99 82.5 ms rss 297 MiB disconnects=0
[zone] t=270.0s tick=5400 clients=1000 tick p50=12.74 ms p99=59.58 ms max=221.23 ms sent=4159016 skipped=0 KB/s/client≈3.00
[bots] t=300.0s connected=1000 down≈2811 B/s/bot rtt p99 122.0 ms rss 294 MiB disconnects=0
[zone] t=300.0s tick=5984 clients=1000 tick p50=13.40 ms p99=66.98 ms max=279.70 ms sent=4773019 skipped=0 KB/s/client≈2.96
[zone] t=330.0s tick=6583 clients=1000 tick p50=13.99 ms p99=67.47 ms max=279.70 ms sent=5401974 skipped=0 KB/s/client≈2.94
[bots] t=330.0s connected=1000 down≈2760 B/s/bot rtt p99 199.5 ms rss 294 MiB disconnects=0
[bots] t=360.0s connected=1000 down≈3066 B/s/bot rtt p99 121.0 ms rss 294 MiB disconnects=0
[zone] t=360.0s tick=7182 clients=1000 tick p50=14.43 ms p99=70.03 ms max=279.70 ms sent=6031002 skipped=0 KB/s/client≈2.92
[bots] t=390.0s connected=1000 down≈2531 B/s/bot rtt p99 216.0 ms rss 289 MiB disconnects=0
[zone] t=390.1s tick=7703 clients=1000 tick p50=14.96 ms p99=391.06 ms max=391.06 ms sent=6581952 skipped=0 KB/s/client≈2.88
[bots] t=420.0s connected=1000 down≈2757 B/s/bot rtt p99 281.0 ms rss 291 MiB disconnects=0
[zone] t=420.3s tick=8248 clients=1000 tick p50=15.39 ms p99=391.06 ms max=391.06 ms sent=7156969 skipped=0 KB/s/client≈2.85
[zone] t=450.0s tick=8764 clients=1000 tick p50=15.69 ms p99=391.06 ms max=391.06 ms sent=7702991 skipped=0 KB/s/client≈2.82
[bots] t=450.0s connected=1000 down≈2800 B/s/bot rtt p99 135.5 ms rss 289 MiB disconnects=0
[bots] t=480.0s connected=1000 down≈1404 B/s/bot rtt p99 278.0 ms rss 285 MiB disconnects=0
[zone] t=480.3s tick=9082 clients=1000 tick p50=16.11 ms p99=433.40 ms max=433.40 ms sent=8050951 skipped=7 KB/s/client≈2.73
[bots] t=510.0s connected=1000 down≈2196 B/s/bot rtt p99 273.0 ms rss 286 MiB disconnects=0
[zone] t=510.2s tick=9440 clients=1000 tick p50=16.54 ms p99=513.36 ms max=513.36 ms sent=8439003 skipped=7 KB/s/client≈2.67
[bots] t=540.0s connected=1000 down≈400 B/s/bot rtt p99 958.5 ms rss 283 MiB disconnects=0
…

# Zone soak summary from logs/evidence/M1-04C/metrics.json (generated by tools/zone-soak-report.py)
run: 1000 bots over WebSocket on loopback against the in-process zone server: stepped ramp 100 -> 250 -> 500 -> 1000 (30 s a step: connects over the first half, holds the second), then a 600 s hold (bandwidth per bot and memory drift are measured over the hold), then a 1000 close each
harness: 1000 bots, steps [100, 250, 500, 1000] x 30 s, hold 600 s, run 720.917 s, 4 bot workers, 4 snapshot workers, fieldSpawnPermille 500
machine: macos aarch64, 8 cores; load average (1/5/15 min) t=0s 358.28 410.79 340.55; t=60s 374.48 405.76 343.44; t=120s 377.78 401.32 346.04; t=180s 334.99 385.52 343.94; t=240s 276.61 359.46 337.02; t=300s 252.82 337.54 330.35; t=360s 211.67 310.52 320.74; t=420s 200.89 289.79 312.31; t=480s 246.58 283.21 308.11; t=540s 318.26 295.28 310.82; t=600s 312.69 300.47 311.86; t=660s 228.61 279.46 303.29; t=720s 251.60 273.62 299.28; t=721s 251.60 273.62 299.28

Card criteria (M1-04 / M1-04C):
  PASS  1,000 bots connected through the hold: joined 1000/1000, fewest connected in a hold second 1000
  PASS  no disconnects: 0 disconnects, 0 connect errors, 1000 clean closes at the end
  FAIL  server loop p99 <= 15.0 ms (whole run, ramp + hold, 12497 loops): p50 17.8 p99 1685.838 max 1685.838 ms; over target 7577 loops, dropped ticks 1754
        hold 1 s windows: p99 median 82.22, p95 398.81, max 1685.84 ms; 601 of 601 windows had a loop over target
        on-CPU: tick thread per loop mean 4.509 p99 20.04 ms; snapshot workers summed mean 7.858 p99 11.13 ms
  PASS  avg downstream <= 12 KB/s/client (hold): mean 2.42 p95 8.26 max 8.44 KB/s
  PASS  every client <= 32 KB/s hard cap (crowded town incl.): max 8.44 KB/s
  PASS  memory flat within ±5% over the hold: drift -4.274% (slope -1274.26 KiB/min, mean 291 MiB, first minute 298.2 -> last minute 292.5 MiB, -1.911%)
  info  RTT ping->pong: p50 42.408 p99 682.987 max 3732.963 ms over 633547 pongs

All harness checks: allJoined PASS, noDisconnects PASS, avgDownstreamWithinTarget PASS, everyClientWithinHardCap PASS, missedTicksUnder1Percent PASS, memoryFlatWithinDrift PASS, loopP99WithinTarget FAIL, noStaleOrDroppedInputs PASS, framesSkippedUnder1Percent PASS, ticksDroppedUnder1Percent FAIL, noSnapshotErrors PASS, noThreadsLeft PASS
Overall: FAIL

Reading (M1-04C worker): the loop p99 miss and the dropped ticks are machine load, not the zone. The 1-minute load
average was 201-378 on 8 cores for the whole run (25-47 runnable threads per core: other projects' clang builds,
ffmpeg, Chrome, Claude), so the tick thread often waited for a core: loop p50 17.8 ms wall against tick-thread CPU
4.51 ms mean per loop and snapshot workers 7.86 ms summed (on-CPU work ~12 ms spread over 4 threads); the same build
held p99 12.1 ms at load 14-100 in M1-04B. Budgets are unchanged. Bots, bandwidth and memory pass: 1,000/1,000
connected through the 10-minute hold, 0 disconnects, 2.42 KB/s mean down, RSS drift -4.27 % (shrinking; macOS memory
pressure from the same load), within the ±5 % limit. Re-run `pnpm zone:bots -- --steps 100,250,500,1000 --step-s 30
--hold-s 600` when the load average is near or below the core count.

{
  "task": "M1-04",
  "generatedBy": "pnpm zone:bots (cargo run --release -p zoen-bots --bin bots)",
  "what": "1000 bots over WebSocket on loopback against the in-process zone server: stepped ramp 100 -> 250 -> 500 -> 1000 (30 s a step: connects over the first half, holds the second), then a 600 s hold (bandwidth per bot and memory drift are measured over the hold), then a 1000 close each",
  "behaviours": {"walk": "waypoint wander steered by the own exact position in each snapshot; one input per snapshot (20/s), an ack per snapshot, a ping per second", "fight": "hunters cast every castEveryS once inside their zone and stand still castMs; the cast is a bot-side timer (counted, not sent): protocol v1 input has no action/skill bits", "chat": "not in protocol v1: a bot-side timer every chatEveryS (counted, not sent)", "mix": {"townSharePermille": 250, "townRadiusMm": 50000, "pauseMs": [0, 3000], "castMs": 800, "castEveryMs": [2000, 6000], "chatEveryMs": [15000, 45000], "source": "netcode.json loadTest (botMix proposed by M1-04)"}},
  "harness": {"bots": 1000, "workers": 4, "rampS": 120, "steps": [100, 250, 500, 1000], "stepS": 30, "snapshotWorkers": 4, "fieldSpawnPermille": 500, "holdS": 600, "runS": 720.917, "threads": "bots run on 4 poll(2) worker threads, not one OS thread per bot: the in-process server already runs two threads per client plus the tick on this 8-core Mac, and a worker wakes about once per tick for all its sockets instead of 1,000 threads waking 40+ times a second"},
  "machine": {"os": "macos", "arch": "aarch64", "availableParallelism": 8, "loadAverageBefore": "358.28 410.79 340.55", "loadAverageAfter": "251.60 273.62 299.28", "rssBeforeKiB": 2304, "loadAverage": [{"tS": 0.0, "load": "358.28 410.79 340.55"}, {"tS": 60.0, "load": "374.48 405.76 343.44"}, {"tS": 120.0, "load": "377.78 401.32 346.04"}, {"tS": 180.0, "load": "334.99 385.52 343.94"}, {"tS": 240.0, "load": "276.61 359.46 337.02"}, {"tS": 300.0, "load": "252.82 337.54 330.35"}, {"tS": 360.0, "load": "211.67 310.52 320.74"}, {"tS": 420.0, "load": "200.89 289.79 312.31"}, {"tS": 480.0, "load": "246.58 283.21 308.11"}, {"tS": 540.0, "load": "318.26 295.28 310.82"}, {"tS": 600.0, "load": "312.69 300.47 311.86"}, {"tS": 660.0, "load": "228.61 279.46 303.29"}, {"tS": 720.0, "load": "251.60 273.62 299.28"}, {"tS": 721.1, "load": "251.60 273.62 299.28"}], "loadNote": "vm.loadavg (1/5/15 min) at the start, every minute and at the end; this Mac also runs other work"},
  "thresholds": {"loopP99Ms": 15.000, "avgDownstreamBps": 12000, "hardCapBps": 32000, "memoryDriftPercent": 5, "source": "netcode.json tick.targetP99Ms, loadTest.avgDownstreamKBps, snapshot.hardCapKBps (KB = 1,000 B), loadTest.memoryDriftPercent"},
  "bots": {"requested": 1000, "joined": 1000, "connectErrors": 0, "disconnects": 0, "cleanCloses": 1000, "inField": 758, "spawnedInField": 500, "snapshots": 11031494, "fullSnapshots": 1017, "missedTicks": 11870, "inputs": 11031494, "acks": 11031494, "pings": 640827, "pongs": 633547, "waypointsReached": 19717, "castsNotSent": 100916, "chatLinesNotSent": 21121},
  "downstreamBpsPerBotHold": {"mean": 2419.5, "p50": 578.1, "p95": 8259.0, "p99": 8370.4, "max": 8443.9, "samples": 1000},
  "upstreamBpsPerBotHold": {"mean": 447.2, "p50": 447.2, "p95": 447.5, "p99": 447.6, "max": 447.7, "samples": 1000},
  "rttMs": {"mean": 86.811, "p50": 42.408, "p95": 314.754, "p99": 682.987, "max": 3732.963, "samples": 633547},
  "memory": {"what": "resident memory of this process (zone server and bots share it) over the hold, sampled every second (ps rss); drift = least-squares slope x hold length / mean hold RSS", "holdSamples": 601, "rssMeanKiB": 298170, "slopeKiBPerMin": -1274.26, "driftPercent": -4.274, "firstMinuteMeanKiB": 305336, "lastMinuteMeanKiB": 299501, "firstToLastMinutePercent": -1.911, "limitPercent": 5},
  "botSeries": {"windowS": 1, "what": "per second as the bots saw it: connected = joined - disconnects; bytes per connected bot; RTT percentiles of that second's pongs (0.5 ms buckets, upper edge; 0 = no pong); process RSS", "samples": [
    {"tS": 1.0, "joined": 7, "connected": 7, "disconnects": 0, "downBpsPerBot": 313, "upBpsPerBot": 281, "pongs": 5, "rttP50Ms": 48.5, "rttP99Ms": 62.5, "rssKiB": 8240},
    {"tS": 2.0, "joined": 13, "connected": 13, "disconnects": 0, "downBpsPerBot": 556, "upBpsPerBot": 423, "pongs": 10, "rttP50Ms": 50.0, "rttP99Ms": 55.5, "rssKiB": 10432},
    {"tS": 3.0, "joined": 20, "connected": 20, "disconnects": 0, "downBpsPerBot": 743, "upBpsPerBot": 451, "pongs": 15, "rttP50Ms": 48.0, "rttP99Ms": 62.0, "rssKiB": 12480},
    {"tS": 4.0, "joined": 27, "connected": 27, "disconnects": 0, "downBpsPerBot": 812, "upBpsPerBot": 465, "pongs": 25, "rttP50Ms": 43.0, "rttP99Ms": 59.0, "rssKiB": 14272},
    {"tS": 5.0, "joined": 34, "connected": 34, "disconnects": 0, "downBpsPerBot": 909, "upBpsPerBot": 497, "pongs": 30, "rttP50Ms": 46.5, "rttP99Ms": 54.0, "rssKiB": 16448},
    {"tS": 6.0, "joined": 40, "connected": 40, "disconnects": 0, "downBpsPerBot": 961, "upBpsPerBot": 472, "pongs": 35, "rttP50Ms": 50.5, "rttP99Ms": 54.0, "rssKiB": 18272},
    {"tS": 7.0, "joined": 47, "connected": 47, "disconnects": 0, "downBpsPerBot": 1009, "upBpsPerBot": 494, "pongs": 45, "rttP50Ms": 53.5, "rttP99Ms": 57.0, "rssKiB": 20352},
    {"tS": 8.0, "joined": 54, "connected": 54, "disconnects": 0, "downBpsPerBot": 1106, "upBpsPerBot": 494, "pongs": 50, "rttP50Ms": 49.5, "rttP99Ms": 58.5, "rssKiB": 22432},
    {"tS": 9.0, "joined": 60, "connected": 60, "disconnects": 0, "downBpsPerBot": 1319, "upBpsPerBot": 505, "pongs": 55, "rttP50Ms": 50.0, "rttP99Ms": 53.0, "rssKiB": 24224},
    {"tS": 10.0, "joined": 67, "connected": 67, "disconnects": 0, "downBpsPerBot": 1394, "upBpsPerBot": 505, "pongs": 65, "rttP50Ms": 50.0, "rttP99Ms": 59.0, "rssKiB": 26368},
    {"tS": 11.0, "joined": 73, "connected": 73, "disconnects": 0, "downBpsPerBot": 1417, "upBpsPerBot": 512, "pongs": 70, "rttP50Ms": 50.0, "rttP99Ms": 56.0, "rssKiB": 28448},
…