Files
CosmicClash/Game/scripts/replay_log.gd
T
Josh Creek 866efa0d9b fix(multiplayer): server no longer rate-limits a backlog it caused itself
Closes task 5.10's three recording gaps, and the gap-closing found a real
input-loss bug.

Replay log: a failed write now ends the log permanently instead of
desyncing every later record's framing; close() is called from _exit_tree
with a summary, since the RefCounted destructor closes it implicitly but
never says whether the log is complete; rejected packets are recorded
with their reason in the kind byte (framing unchanged, FORMAT_VERSION 2
so "no rejects" differs from "this build never recorded them"). Recording
is capped at 8 per peer per window - uncapped, the diagnostic is a remote
disk-fill amplifier, since the attacker picks the packet rate. Uncapped
totals live on MatchSim and survive the peer's disconnect.

The bug: a 2s host stall has the client sending at 60Hz throughout, and
ENet delivers that whole backlog in the first window after resume - 70 of
an honest client's packets rejected as "rate limit exceeded". Redundancy
does not cover it, because the dropped packets are contiguous: 0 of 70
rescued, and 82 of 923 sequences (8.88%, ~1.4s of input) never reached
the server, against 0.00% with no stall. Every prediction gate passed.

Fixed by granting each already-tracked peer a capped, two-window packet
grace when the server detects its own wall-clock stall. Rate-limit
rejects 70 -> 0, sequences missing 8.88% -> 0.00%, seq-guard rejects
9 -> 0. Controls on the unfixed build lost 4.34/7.52/7.86%. All three
abuse roles still disconnect and no flood induced a stall, so the grace
cannot be farmed.

Also corrects an earlier wrong conclusion: the reviewer's free-flight
p95 0.688 is real and reproduces on two processes with 0.0% snapshot
loss. The plain --role=client drive fails the 0.5 free-flight bound in
3 of 8 runs because that drive is mostly a contact test - the harness
comment already said so - leaving a cohort as small as 12 samples.
Near-surface error is genuinely several times open-air error, so the
calibrated bound now belongs to --exercise-free-flight alone and the
plain role asserts the always-well-sampled all-cohort percentiles at
1.2/2.0, printing the free-flight numbers as reported-not-asserted.
6/6 plain runs pass where 3/7 failed; tightening to 0.3 still fails.

tools/replay_dump.gd reads a log back: counts by kind, plus how much of
the input sequence stream reached the server once redundancy is counted.
2026-08-21 16:10:43 +01:00

172 lines
6.5 KiB
GDScript

class_name ReplayLog
extends RefCounted
# Append-only binary server replay log (multiplayer-todo.md task 5.10).
#
# The highest-value debuggability investment in Phase 5, and cheap precisely
# because the packets are ALREADY flat bytes: this stores them verbatim rather
# than re-serialising game state. Without it, "my ship snapped" is permanently
# unreproducible from a field report — the CI gate catches regressions, but it
# cannot debug a player's bad night.
#
# Deliberately a standalone RefCounted with no scene/RPC dependency, like
# net_codec.gd and input_jitter_buffer.gd, so it can be unit-tested against a
# scripted record/read cycle with no live match.
#
# Format. Little-endian throughout, matching StreamPeerBuffer's own defaults
# and NetCodec's wire encoding:
#
# magic u32 'CCRP' (0x50524343)
# version u16 FORMAT_VERSION
# tick_hz u16 so a reader can convert ticks to seconds without guessing
# then, repeated:
# kind u8 RecordKind
# tick u32 server tick (Engine.get_physics_frames())
# peer_id u32 sender for INPUT, 0 for SNAPSHOT
# length u16 payload byte count
# payload length bytes, exactly as it went on the wire
#
# `length` is a u16 because both hot-path packets are far under 64KB (a 1v1
# snapshot is ~59 bytes) and MatchSim.MAX_INPUT_LENGTH already rejects
# anything larger on the way in.
#
# Framing is kind-agnostic, so new RecordKind values are additive — a reader
# that doesn't know a kind still walks past it correctly. The version bump to 2
# exists anyway because absence is otherwise ambiguous: without it, a log with
# no REJECTED_* records cannot be told apart from one written by a build that
# never recorded rejections in the first place, which is exactly the question
# "the server dropped my input" needs answered.
const MAGIC := 0x50524343
const FORMAT_VERSION := 2
const HEADER_SIZE := 8
const RECORD_HEADER_SIZE := 11
enum RecordKind {
INPUT = 0, # client -> server, accepted and handed to the jitter buffer
SNAPSHOT = 1, # server -> client, as sent
# Rejections. An accepted-input-only log answers "what did the server
# simulate", but the field report that actually needs a replay is usually
# "my input did nothing" — and the packets that would explain it are
# precisely the ones the old log discarded. Each reason is its own kind
# rather than a reason field, so the framing above is unchanged.
REJECTED_MALFORMED = 2, # failed §3.1 step 3 framing validation
REJECTED_RATE_LIMIT = 3, # over budget for the current 1s window
REJECTED_SEQ_GUARD = 4, # seq beyond the slot's ingest bound (§3.1 step 4)
}
var _file: FileAccess = null
var records_written := 0
var bytes_written := 0
# Set once a write actually fails (disk full, removed volume). Everything after
# it is dropped: a partial record would desync the framing of every record that
# follows, turning a truncation into a corrupt file.
var write_failed := false
var records_dropped := 0
# Returns OK, or an error code. A replay log is diagnostic: a caller that
# cannot open one should carry on serving the match, not refuse to start.
func open_for_write(path: String) -> Error:
_file = FileAccess.open(path, FileAccess.WRITE)
if _file == null:
return FileAccess.get_open_error()
_file.store_32(MAGIC)
_file.store_16(FORMAT_VERSION)
_file.store_16(SimConstants.TICK_HZ)
bytes_written = HEADER_SIZE
return OK
func is_open() -> bool:
return _file != null
func record_input(tick: int, peer_id: int, payload: PackedByteArray) -> void:
_write(RecordKind.INPUT, tick, peer_id, payload)
func record_snapshot(tick: int, payload: PackedByteArray) -> void:
_write(RecordKind.SNAPSHOT, tick, 0, payload)
# `kind` must be one of the REJECTED_* values; the caller knows why it dropped
# the packet and nothing here can re-derive it.
func record_rejected_input(kind: int, tick: int, peer_id: int, payload: PackedByteArray) -> void:
_write(kind, tick, peer_id, payload)
func _write(kind: int, tick: int, peer_id: int, payload: PackedByteArray) -> void:
if _file == null or write_failed:
return
if payload.size() > 0xFFFF:
# Cannot happen through the real ingress paths (see the header note),
# but truncating silently would corrupt every later record's framing.
push_warning("ReplayLog: dropping an oversized %d-byte payload" % payload.size())
records_dropped += 1
return
_file.store_8(kind)
_file.store_32(tick)
_file.store_32(peer_id)
_file.store_16(payload.size())
if payload.size() > 0:
_file.store_buffer(payload)
# Checked via get_error() rather than the store_* return values because it
# reports the same condition once for the whole record instead of six times,
# and because a diagnostic log that has quietly stopped writing is worse
# than no log at all — the reader would see a plausible short match rather
# than a failure. One write error ends the log permanently.
var err := _file.get_error()
if err != OK:
write_failed = true
records_dropped += 1
push_warning("ReplayLog: write failed (%s) after %d records — log closed early" % [error_string(err), records_written])
_file.close()
_file = null
return
records_written += 1
bytes_written += RECORD_HEADER_SIZE + payload.size()
func close() -> void:
if _file == null:
return
_file.close()
_file = null
# Reads a whole log back. Returns {"tick_hz": int, "records": Array} or an
# empty Dictionary if the file is missing/not a replay log. Static and
# self-contained so an offline tool — or a test — can consume a log without
# instantiating anything.
static func read_all(path: String) -> Dictionary:
var f := FileAccess.open(path, FileAccess.READ)
if f == null:
return {}
if f.get_length() < HEADER_SIZE or f.get_32() != MAGIC:
f.close()
return {}
var version := f.get_16()
var tick_hz := f.get_16()
var records: Array = []
# Bound every read on the declared length rather than trusting EOF:
# FileAccess silently zero-fills past the end, exactly as StreamPeerBuffer
# does, so a truncated file would otherwise decode as an endless run of
# zero-length records at tick 0.
while f.get_position() + RECORD_HEADER_SIZE <= f.get_length():
var kind := f.get_8()
var tick := f.get_32()
var peer_id := f.get_32()
var length := f.get_16()
if f.get_position() + length > f.get_length():
push_warning("ReplayLog: truncated final record in %s" % path)
break
records.append({
"kind": kind,
"tick": tick,
"peer_id": peer_id,
"payload": f.get_buffer(length) if length > 0 else PackedByteArray(),
})
f.close()
return {"version": version, "tick_hz": tick_hz, "records": records}