mirror of
https://github.com/jcreek/CosmicClash.git
synced 2026-09-10 16:04:04 +00:00
fix(agones): stop a dead health loop from passing as a healthy server
Every allocated GameServer reached Ready and was recycled by Agones ~20s later. Health pings are the game process's job by design -- the supervisor has no health implementation at all -- so a server that stops pinging is exactly what Agones is built to reclaim. start_health() armed a Timer on a node that might not be inside the SceneTree. A Timer only ticks inside the tree, so the node reported itself configured, sent nothing, and said nothing about it. It now returns a bool, refuses loudly when unconfigured, and defers to _ready() when called before parenting, so the SDK arms its own timer and no caller has to get the ordering right. server_boot.gd defers the add like every sibling does (§9 gotcha 27) and logs when AGONES_SDK_HTTP_PORT is missing, which previously read identically to a healthy start. Also bounded the in-flight latch: it is set across an await, so a request that never completes would silence health permanently. Defence in depth rather than an observed fault. Tests target the contract rather than the mechanism: a test that parents the SDK correctly and asserts pings passes with the bug present, because the defect was in the wiring. The unit tests assert start_health() cannot claim success out of tree, and were confirmed to fail against the previous code. The smoke gains a counting sidecar and asserts a *repeating* ping -- it reports "health pings in 3.0s = 1, want at least 2" when the loop is broken, which is the production symptom exactly. It is also now actually run: nothing referenced it before. Two diagnostic fixes, both of which changed conclusions during this work: The kind gate only built the game-server image when the tag was absent, so a local rerun silently verified whatever was built last. That is why local runs and CI disagreed about the same commit. It now builds by default, with KIND_REUSE_GAME_SERVER_IMAGE=1 as the opt-in fast path. The failure dump logged only not-ready pods, and used --all-containers with a shared tail. A GameServer recycled after reaching Ready leaves no unready pod behind, and the Agones sidecar out-logs the game server, so the relevant output was never captured. It now dumps every pod, per container, current and previous, plus the GameServer and Fleet resources -- Agones' own state machine is what rejects these.
This commit is contained in:
@@ -12,6 +12,21 @@ const MAX_ANNOTATION_VALUE_LENGTH := 4096
|
||||
var _base_url := ""
|
||||
var _health_timer: Timer = null
|
||||
var _health_in_flight := false
|
||||
var _health_started_msec := 0
|
||||
# Set when start_health() is called before this node is inside the tree, so
|
||||
# _ready() can arm the timer at the first moment it is legal to do so.
|
||||
var _health_pending := false
|
||||
|
||||
|
||||
# Health is armed here rather than by the caller. A Timer only ticks while its
|
||||
# owner is inside the SceneTree, so arming it from a caller that has not yet
|
||||
# parented this node produces a node that looks configured and never pings —
|
||||
# which is exactly how every allocated GameServer silently failed its Agones
|
||||
# health check and was recycled.
|
||||
func _ready() -> void:
|
||||
if _health_pending:
|
||||
_health_pending = false
|
||||
_arm_health()
|
||||
|
||||
|
||||
func configure_from_environment() -> bool:
|
||||
@@ -33,8 +48,29 @@ func is_available() -> bool:
|
||||
return not _base_url.is_empty()
|
||||
|
||||
|
||||
func start_health() -> void:
|
||||
if not is_available() or _health_timer != null:
|
||||
# Returns whether health pings are running. It is a bool rather than void
|
||||
# because every way this can fail used to be silent, and a game server that
|
||||
# believes it is healthy while sending nothing is worse than one that refuses
|
||||
# to start: Agones recycles the former every ~20 seconds forever.
|
||||
func start_health() -> bool:
|
||||
if not is_available():
|
||||
push_error("AgonesSDK: start_health() before configuration; no health pings will be sent")
|
||||
return false
|
||||
if _health_timer != null:
|
||||
return true
|
||||
if not is_inside_tree():
|
||||
# Deferred rather than fatal: the caller may legitimately configure
|
||||
# before parenting. _ready() arms it. Still reported, because if the
|
||||
# node is never parented this is the whole failure.
|
||||
_health_pending = true
|
||||
push_warning("AgonesSDK: start_health() called outside the tree; deferring until ready")
|
||||
return false
|
||||
_arm_health()
|
||||
return true
|
||||
|
||||
|
||||
func _arm_health() -> void:
|
||||
if _health_timer != null:
|
||||
return
|
||||
_health_timer = Timer.new()
|
||||
_health_timer.name = "AgonesHealth"
|
||||
@@ -46,6 +82,10 @@ func start_health() -> void:
|
||||
_send_health()
|
||||
|
||||
|
||||
func health_is_running() -> bool:
|
||||
return _health_timer != null and is_inside_tree()
|
||||
|
||||
|
||||
func stop_health() -> void:
|
||||
if _health_timer != null:
|
||||
_health_timer.stop()
|
||||
@@ -76,9 +116,20 @@ static func annotation_is_valid(key: String, value: String) -> bool:
|
||||
|
||||
|
||||
func _send_health() -> void:
|
||||
if _health_in_flight or not is_available():
|
||||
if not is_available():
|
||||
return
|
||||
# The latch stops overlapping requests, but it must never become permanent.
|
||||
# It is set across an await, and a request that never completes would
|
||||
# otherwise silence health for the lifetime of the process. HTTPRequest's
|
||||
# own timeout normally resolves this; the elapsed check is the backstop for
|
||||
# the case where request_completed never fires at all.
|
||||
if _health_in_flight:
|
||||
var stuck_for := Time.get_ticks_msec() - _health_started_msec
|
||||
if stuck_for < int(REQUEST_TIMEOUT_SECONDS * 2.0 * 1000.0):
|
||||
return
|
||||
push_warning("Agones health ping did not complete in %dms; sending another" % stuck_for)
|
||||
_health_in_flight = true
|
||||
_health_started_msec = Time.get_ticks_msec()
|
||||
var status := await health()
|
||||
_health_in_flight = false
|
||||
if status < 200 or status >= 300:
|
||||
|
||||
@@ -91,11 +91,19 @@ func _ready() -> void:
|
||||
if agones_managed:
|
||||
_agones = AgonesSDKScript.new()
|
||||
_agones.name = "AgonesSDK"
|
||||
# Health creates and starts a Timer immediately, so the SDK node must be
|
||||
# in the tree before start_health() runs.
|
||||
get_tree().root.add_child(_agones)
|
||||
# Configure before parenting, then request health and defer the add like
|
||||
# every other node here (§9 gotcha 27: add_child() on get_tree().root
|
||||
# from inside _ready() is refused because the tree is still attaching
|
||||
# this very node, and the refusal is not catchable from GDScript). The
|
||||
# SDK arms its own timer in _ready(), so nothing depends on the order
|
||||
# these deferred calls happen to flush in.
|
||||
if _agones.configure_from_environment():
|
||||
_agones.start_health()
|
||||
else:
|
||||
# Never silent: without this the log looks identical to a healthy
|
||||
# server right up until Agones recycles it.
|
||||
printerr("cosmic-clash-server: AGONES_SDK_HTTP_PORT is missing or invalid; Agones health pings are disabled")
|
||||
get_tree().root.add_child.call_deferred(_agones)
|
||||
if allocated_mode:
|
||||
var roster_file := String(config.get_value("join-authorisations-file"))
|
||||
var key_file := String(config.get_value("join-authorisations-key-file"))
|
||||
|
||||
@@ -1,33 +1,130 @@
|
||||
extends SceneTree
|
||||
|
||||
# Headless smoke for the Agones SDK bridge. Run by
|
||||
# scripts/verify_multiplayer_local.sh:
|
||||
# godot --headless --path Game --script res://tests/agones_sdk_smoke.gd
|
||||
#
|
||||
# Phase 1 drives each REST call directly. Phase 2 covers what phase 1 cannot:
|
||||
# that start_health() produces a *repeating* ping. That is the property Agones
|
||||
# actually enforces -- one ping proves nothing, because the Fleet recycles any
|
||||
# GameServer that stops pinging for periodSeconds * failureThreshold -- and its
|
||||
# absence is what silently recycled every allocated server.
|
||||
|
||||
const ServerControlScript = preload("res://scripts/server_control.gd")
|
||||
const AgonesSDKScript = preload("res://scripts/agones_sdk.gd")
|
||||
const PORT := 18081
|
||||
const HEALTH_PORT := 18082
|
||||
# start_health() pings every 2s, so three seconds must contain at least two.
|
||||
const HEALTH_OBSERVATION_SECONDS := 3.0
|
||||
const MINIMUM_EXPECTED_PINGS := 2
|
||||
|
||||
|
||||
# Counting stand-in for the Agones sidecar. ServerControl answers /health but
|
||||
# cannot report how often it was called, and asserting repetition is the whole
|
||||
# point here, so this counts rather than changing production code for a test.
|
||||
class CountingSidecar extends Node:
|
||||
var health_pings := 0
|
||||
var _listener := TCPServer.new()
|
||||
var _peers: Array = []
|
||||
|
||||
func start(port: int) -> Error:
|
||||
return _listener.listen(port, "127.0.0.1")
|
||||
|
||||
func stop() -> void:
|
||||
_listener.stop()
|
||||
for peer in _peers:
|
||||
if is_instance_valid(peer):
|
||||
peer.disconnect_from_host()
|
||||
_peers.clear()
|
||||
|
||||
func _process(_delta: float) -> void:
|
||||
while _listener.is_connection_available():
|
||||
_peers.append(_listener.take_connection())
|
||||
for i in range(_peers.size() - 1, -1, -1):
|
||||
var peer: StreamPeerTCP = _peers[i]
|
||||
if peer.get_status() != StreamPeerTCP.STATUS_CONNECTED:
|
||||
_peers.remove_at(i)
|
||||
continue
|
||||
var available := peer.get_available_bytes()
|
||||
if available <= 0:
|
||||
continue
|
||||
var request := peer.get_utf8_string(available)
|
||||
if "\r\n\r\n" not in request:
|
||||
continue
|
||||
if request.begins_with("POST /health"):
|
||||
health_pings += 1
|
||||
var body := "{}"
|
||||
peer.put_data(("HTTP/1.1 200 OK\r\nContent-Type: application/json\r\nContent-Length: %d\r\nConnection: close\r\n\r\n%s" % [body.length(), body]).to_utf8_buffer())
|
||||
peer.disconnect_from_host()
|
||||
_peers.remove_at(i)
|
||||
|
||||
|
||||
func _init() -> void:
|
||||
if not await _direct_calls_smoke():
|
||||
quit(1)
|
||||
return
|
||||
if not await _repeating_health_smoke():
|
||||
quit(1)
|
||||
return
|
||||
print("Agones SDK smoke passed")
|
||||
quit(0)
|
||||
|
||||
|
||||
func _direct_calls_smoke() -> bool:
|
||||
var fake_sidecar = ServerControlScript.new()
|
||||
root.add_child(fake_sidecar)
|
||||
if fake_sidecar.start(PORT) != OK:
|
||||
printerr("fake sidecar failed to bind")
|
||||
quit(1)
|
||||
return
|
||||
return false
|
||||
fake_sidecar.set_process_ready(true)
|
||||
var sdk = AgonesSDKScript.new()
|
||||
root.add_child(sdk)
|
||||
if not sdk.configure_for_testing("http://127.0.0.1:%d" % PORT):
|
||||
printerr("SDK test configuration failed")
|
||||
quit(1)
|
||||
return
|
||||
return false
|
||||
await process_frame
|
||||
var health_status := await sdk.health()
|
||||
var ready_status := await sdk.mark_ready()
|
||||
var annotation_status := await sdk.set_annotation("match", "result")
|
||||
var shutdown_status := await sdk.shutdown()
|
||||
fake_sidecar.stop()
|
||||
fake_sidecar.queue_free()
|
||||
sdk.queue_free()
|
||||
if health_status != 200 or ready_status != 200 or annotation_status < 400 or shutdown_status < 400:
|
||||
printerr("Agones SDK smoke statuses health=%d ready=%d annotation=%d shutdown=%d" % [health_status, ready_status, annotation_status, shutdown_status])
|
||||
quit(1)
|
||||
return
|
||||
print("Agones SDK smoke passed")
|
||||
fake_sidecar.stop()
|
||||
quit(0)
|
||||
return false
|
||||
return true
|
||||
|
||||
|
||||
func _repeating_health_smoke() -> bool:
|
||||
var sidecar := CountingSidecar.new()
|
||||
root.add_child(sidecar)
|
||||
if sidecar.start(HEALTH_PORT) != OK:
|
||||
printerr("counting sidecar failed to bind")
|
||||
return false
|
||||
|
||||
# Configure before parenting and let the node arm its own timer on _ready(),
|
||||
# which is exactly how server_boot.gd wires it in an allocated pod.
|
||||
var sdk = AgonesSDKScript.new()
|
||||
if not sdk.configure_for_testing("http://127.0.0.1:%d" % HEALTH_PORT):
|
||||
printerr("health SDK configuration failed")
|
||||
return false
|
||||
if sdk.start_health():
|
||||
printerr("start_health() reported success while the node was outside the tree")
|
||||
return false
|
||||
root.add_child(sdk)
|
||||
await process_frame
|
||||
if not sdk.health_is_running():
|
||||
printerr("health loop did not arm once the node entered the tree")
|
||||
return false
|
||||
|
||||
await create_timer(HEALTH_OBSERVATION_SECONDS).timeout
|
||||
var observed := sidecar.health_pings
|
||||
sdk.stop_health()
|
||||
sidecar.stop()
|
||||
sdk.queue_free()
|
||||
sidecar.queue_free()
|
||||
if observed < MINIMUM_EXPECTED_PINGS:
|
||||
printerr("Agones health pings in %.1fs = %d, want at least %d; the health loop is not repeating" % [HEALTH_OBSERVATION_SECONDS, observed, MINIMUM_EXPECTED_PINGS])
|
||||
return false
|
||||
return true
|
||||
|
||||
@@ -17,3 +17,40 @@ func test_annotation_validation_rejects_header_injection_and_oversized_values()
|
||||
assert_true(not AgonesSDKScript.annotation_is_valid("bad\nkey", "value"), "annotation key newline is rejected")
|
||||
assert_true(not AgonesSDKScript.annotation_is_valid("key", "bad\rvalue"), "annotation value newline is rejected")
|
||||
assert_true(not AgonesSDKScript.annotation_is_valid("key", "x".repeat(4097)), "oversized annotation is rejected")
|
||||
|
||||
|
||||
# Regression: every allocated GameServer reached Ready and was then recycled by
|
||||
# Agones ~20s later, because start_health() armed a Timer on a node that was
|
||||
# never parented. A Timer only ticks inside the SceneTree, so the process
|
||||
# reported healthy while sending no pings at all, and nothing said so.
|
||||
#
|
||||
# These are deliberately synchronous: test_runner.gd calls test methods without
|
||||
# awaiting, so anything needing a live tree or an HTTP round trip belongs in
|
||||
# tests/agones_sdk_smoke.gd instead. What is asserted here is the contract that
|
||||
# makes the silent case impossible.
|
||||
func test_start_health_refuses_when_not_configured() -> void:
|
||||
var sdk = AgonesSDKScript.new()
|
||||
assert_true(not sdk.start_health(), "health cannot start before a sidecar URL is known")
|
||||
assert_true(not sdk.health_is_running(), "no timer is armed without configuration")
|
||||
sdk.queue_free()
|
||||
|
||||
|
||||
func test_start_health_reports_failure_when_outside_the_tree() -> void:
|
||||
# The exact shape of the production bug: configured, so is_available() is
|
||||
# true and the node looks ready to work, but unparented.
|
||||
var sdk = AgonesSDKScript.new()
|
||||
assert_true(sdk.configure_for_testing("http://127.0.0.1:9358"), "fixture configures")
|
||||
assert_true(sdk.is_available(), "an unparented node still reports available")
|
||||
assert_true(not sdk.start_health(), "start_health() must not claim success outside the tree")
|
||||
assert_true(not sdk.health_is_running(), "no health loop is running outside the tree")
|
||||
sdk.queue_free()
|
||||
|
||||
|
||||
func test_health_is_not_running_until_a_timer_exists() -> void:
|
||||
# health_is_running() is what a caller should trust, rather than
|
||||
# is_available(), which only says a URL was parsed.
|
||||
var sdk = AgonesSDKScript.new()
|
||||
assert_true(not sdk.health_is_running(), "a fresh SDK is not pinging")
|
||||
sdk.configure_for_testing("http://127.0.0.1:9358")
|
||||
assert_true(not sdk.health_is_running(), "configuration alone does not start pinging")
|
||||
sdk.queue_free()
|
||||
|
||||
@@ -40,20 +40,31 @@ dump_cluster_state() {
|
||||
# does not: FailedScheduling, ImagePullBackOff, readiness probe errors.
|
||||
echo "=== namespace ${ns}: recent events ===" >&2
|
||||
kubectl -n "$ns" get events --sort-by=.lastTimestamp 2>&1 | tail -40 >&2 || true
|
||||
# Log EVERY pod, not only the not-ready ones. A GameServer that reaches
|
||||
# Ready and is then recycled on a health check leaves no unready pod
|
||||
# behind: the failures are already deleted and the survivors read 2/2
|
||||
# Running, so filtering on readiness dumped nothing useful and the game
|
||||
# server's own output went unseen for several CI runs.
|
||||
for pod in $(kubectl -n "$ns" get pods -o jsonpath='{range .items[*]}{.metadata.name}{"\n"}{end}' 2>/dev/null); do
|
||||
ready="$(kubectl -n "$ns" get pod "$pod" -o jsonpath='{.status.containerStatuses[*].ready}' 2>/dev/null || true)"
|
||||
case "$ready" in
|
||||
*false*|"")
|
||||
echo "=== ${ns}/${pod} is not ready (ready=${ready:-unknown}) ===" >&2
|
||||
kubectl -n "$ns" describe pod "$pod" 2>&1 | tail -35 >&2 || true
|
||||
echo "--- ${ns}/${pod} logs (current) ---" >&2
|
||||
kubectl -n "$ns" logs "$pod" --all-containers --tail=40 >&2 2>&1 || true
|
||||
echo "--- ${ns}/${pod} logs (previous, if it restarted) ---" >&2
|
||||
kubectl -n "$ns" logs "$pod" --all-containers --previous --tail=40 >&2 2>&1 || true
|
||||
;;
|
||||
esac
|
||||
echo "=== ${ns}/${pod} (ready=${ready:-unknown}) ===" >&2
|
||||
kubectl -n "$ns" describe pod "$pod" 2>&1 | tail -35 >&2 || true
|
||||
# Per container, not --all-containers: the Agones sidecar is far chattier
|
||||
# than the game server, so a shared tail hides exactly the output needed,
|
||||
# and --previous without -c resolves to a container that never restarted.
|
||||
for container in $(kubectl -n "$ns" get pod "$pod" -o jsonpath='{range .spec.containers[*]}{.name}{"\n"}{end}' 2>/dev/null); do
|
||||
echo "--- ${ns}/${pod}[${container}] logs (current) ---" >&2
|
||||
kubectl -n "$ns" logs "$pod" -c "$container" --tail=60 >&2 2>&1 || true
|
||||
echo "--- ${ns}/${pod}[${container}] logs (previous, if it restarted) ---" >&2
|
||||
kubectl -n "$ns" logs "$pod" -c "$container" --previous --tail=60 >&2 2>&1 || true
|
||||
done
|
||||
done
|
||||
done
|
||||
# Agones' own view: a GameServer can be Unhealthy while its Pod looks fine,
|
||||
# which is precisely the shape of a failed health check.
|
||||
echo "=== Agones GameServers and Fleets ===" >&2
|
||||
kubectl get gameservers --all-namespaces -o wide >&2 2>&1 || true
|
||||
kubectl get fleets --all-namespaces -o wide >&2 2>&1 || true
|
||||
echo "=== helm releases ===" >&2
|
||||
helm list --all-namespaces >&2 2>&1 || true
|
||||
}
|
||||
@@ -92,7 +103,14 @@ fi
|
||||
|
||||
kind delete cluster --name "$cluster_name" >/dev/null 2>&1 || true
|
||||
|
||||
if ! docker image inspect "$game_server_image" >/dev/null 2>&1; then
|
||||
# Build by default. Reusing whatever happens to be tagged locally silently
|
||||
# verifies stale code: a developer fixes the game server, reruns this gate, and
|
||||
# it exercises the previous build because the tag already exists. CI never hits
|
||||
# that because a fresh runner has no image, which is precisely how a local pass
|
||||
# and a CI failure can disagree about the same commit.
|
||||
if [[ "${KIND_REUSE_GAME_SERVER_IMAGE:-}" == 1 ]] && docker image inspect "$game_server_image" >/dev/null 2>&1; then
|
||||
echo "Reusing existing $game_server_image (KIND_REUSE_GAME_SERVER_IMAGE=1); it may not contain local changes"
|
||||
else
|
||||
echo "Building $game_server_image from the pinned game-server target"
|
||||
docker build --target game-server -t "$game_server_image" .
|
||||
fi
|
||||
|
||||
@@ -48,6 +48,18 @@ echo "local multiplayer gate: bounded fuzz targets"
|
||||
echo "local multiplayer gate: Godot harness"
|
||||
run_godot_harness
|
||||
|
||||
# The Agones SDK smoke needs a live SceneTree and awaits an HTTP round trip, so
|
||||
# it cannot live in test_runner.tscn -- that runner calls test methods without
|
||||
# awaiting. It covers the property the unit tests structurally cannot: that
|
||||
# start_health() produces a *repeating* ping, which is what Agones enforces and
|
||||
# whose absence silently recycled every allocated GameServer.
|
||||
echo "local multiplayer gate: Agones SDK smoke"
|
||||
if [[ -x "$godot_bin" ]]; then
|
||||
"$godot_bin" --headless --path "$root_dir/Game" --script res://tests/agones_sdk_smoke.gd
|
||||
else
|
||||
echo "local multiplayer gate: skipping Agones SDK smoke, Godot executable not found ($godot_bin)" >&2
|
||||
fi
|
||||
|
||||
echo "local multiplayer gate: contracts and manifests"
|
||||
python3 -m json.tool "$root_dir/server/contracts/v1/openapi.json" >/dev/null
|
||||
# json.tool only proves the contract parses. test_contracts.py is what actually
|
||||
|
||||
Reference in New Issue
Block a user