Files
windmill/docker/test_entrypoint_extra.sh
Alexander PetricandClaude Opus 5.5 8caf414301 fix(multiplayer): a malformed frame from one client no longer exits the server (#11353)
* fix(multiplayer): don't drop client messages during cold-start token verification

`wss.on('connection')` awaits `verifyToken()` before `setupWSConnection()`
attaches the 'message' listener. On a cold process that await includes the
first `/api/debug/jwks` fetch (~30ms on ECS). A y-websocket client sends sync
step 1 the instant the socket opens, and `ws` drops messages emitted with no
listener attached, so that step 1 was lost and never answered with step 2 —
the client's provider never became `synced`.

Buffer messages from the moment the connection is accepted and replay them, in
order, once `setupWSConnection()` has installed its handlers. Rejected
connections drop the buffer and close with the same 4401/4403 codes as before.

Also prefetch the public key at startup when WINDMILL_BASE_URL is set. That is
insurance, not the fix: a connection arriving before the prefetch resolves
still relies on the buffer.

Adds `npm test` in multiplayer/ (node:test, no docker or backend needed) with a
fake JWKS endpoint that answers with a delay, which holds the cold window open
and makes the race deterministic; wired into the existing test_extra CI job.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>

* fix(multiplayer): cap what an unauthenticated peer can buffer pre-auth

Review follow-up.

The pre-auth buffer was unbounded: `ws` sets no `maxPayload` here and the JWKS
fetch has no timeout, so a peer that never authenticates could stream frames
into memory for as long as `verifyToken` was stalled. Cap it at 32 frames /
1 MiB — a real client only has sync step 1 and its first awareness update in
flight there — and close 1009 past that, dropping what was buffered.

A socket closed during verification (by the peer, or by that cap) is no longer
handed to setupWSConnection: it would be added to `doc.conns` with a 'close'
listener that can never fire.

The startup prefetch's .catch was dead code — getPublicKey() logs its own
failures and resolves to null rather than rejecting.

Test helper: pin REQUIRE_SIGNED_MULTIPLAYER_REQUESTS and BASE_INTERNAL_URL so an
ambient value cannot turn the rejection tests into false passes; bind the JWKS
server on port 0 instead of a released probe port, and retry the spawned server
on EADDRINUSE; destroy still-delayed JWKS responses on teardown, since
server.close() waits for in-flight requests.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>

* test(multiplayer): gate the JWKS response instead of delaying it

Review follow-up.

The cold window was held open by a 1500 ms delay on the fake JWKS response, but
that timer started when the startup prefetch reached the fake server, not when
the client sent its first frame. A slow enough machine could load the key before
the client connected, and the race test would then pass without ever exercising
the buffer — a false pass.

The fake JWKS server now parks every response until the test calls release(), so
the server provably holds no key while the client is sending. The race test
releases only after both frames are written to the socket, and asserts the
server has not logged the key as loaded at that point; the flood test never
releases until after the cap has closed the connection.

What is left to wall-clock time is 250 ms for bytes already written to the socket
to cross loopback into an otherwise idle server, rather than a window that had to
cover process startup, connect and handshake.

Also drops the prefetch precondition from the forged-token and flood tests so
each test still maps to one behaviour. Suite runs in ~1.1s instead of ~5.3s.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>

* fix(multiplayer): survive a malformed frame instead of exiting the process

`setupWSConnection`'s message handler decoded whatever an authenticated peer
put on the wire with no guard: `decoding.readVarUint`,
`syncProtocol.readSyncMessage` and `awarenessProtocol.applyAwarenessUpdate` all
throw on input they cannot parse, `ws` re-emits a listener's exception on the
process, and server.mjs installs no `uncaughtException` handler. One bad frame
from one client therefore killed the whole multiplayer server, taking every
other document and every other client with it.

Catch decode/apply failures, log the document, the client address and the error
message (never the payload), and close only the offending connection with 1007
"invalid frame payload data". Frames that arrive once a connection is no longer
OPEN are ignored, so the replay of the pre-auth buffer stops at the first
refusal instead of applying the rest.

docker/entrypoint-extra.sh made that outage permanent: on a service exit it
logged a bare PID and then `wait`ed on the rest, so the container stayed up with
a dead service and the health checks in front of it — which probe the LSP — saw
nothing wrong. It now names the service that died, stops the others through the
same shutdown path SIGTERM uses, and exits non-zero so the orchestrator replaces
the container. The "no services enabled" branch still sleeps.

Tests: multiplayer/test/malformed_frame.test.mjs covers four malformed payloads
from an authenticated client and one replayed out of the pre-auth buffer,
asserting the 1007 close, a live server process, an undisturbed bystander and a
real edit still propagating. docker/test_entrypoint_extra.sh runs the real
entrypoint in a container with stub services.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>

* test(multiplayer): prove the replayed malformed frame really is buffered pre-auth

Assert the server has not yet logged the loaded key when the frame is written,
and give it the same in-flight margin as the cold-start tests before releasing
the JWKS response, so the frame provably goes through the replay path rather
than landing on an already-authenticated connection.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>

* ci(extra): run the entrypoint supervision tests in publish_extra

The multiplayer unit tests already run there; the entrypoint test needs only
docker and the checkout, so run it in the same job, before the image build.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>

* fix(multiplayer): handle WebSocket protocol errors and bound the shutdown

Two crash paths of the same class as the malformed-frame one, from review.

`ws` fails a frame it cannot parse at the protocol level — an unmasked frame
from a client, a reserved opcode, a bad RSV bit — inside its Receiver, before
the application 'message' handler ever sees it, and `receiverOnError` ends with
`websocket.emit('error', err)`. With no 'error' listener that is an unhandled
EventEmitter error, so it exited the process just as a malformed payload did.
(A raw socket error such as ECONNRESET does not: ws 8.21.3's `socketOnError`
swallows those.) Add the listener on the accepted socket, before authentication
so the pre-auth window is covered too, and one on the server.

Log messages now go through `describeError`, which collapses whitespace and
truncates, so nothing that reaches an error message can forge or flood a log
line.

`stop_services` ended in a bare `wait`. On the `docker stop` path dockerd
provides the deadline; the "a service died" path signals itself, so a service
that is wedged or slow to honour SIGTERM would hold the container open
indefinitely — the state that path exists to prevent. Bound it: SIGTERM, wait
SHUTDOWN_GRACE_SECS (10 by default), then SIGKILL the stragglers by name.

Tests: multiplayer/test/socket_error.test.mjs (authenticated and pre-auth
illegal frames, asserting a live process and continued service), a
SIGTERM-ignoring stub scenario in docker/test_entrypoint_extra.sh, and that
harness is now bounded throughout — `timeout -k` on foreground runs, a watchdog
around the backgrounded ones, and an optional outer timeout on `docker run`.
`--entrypoint bash` so the documented windmill-extra:test override runs the
harness instead of the image's real entrypoint. The stubs publish a readiness
marker and the dying one waits for them, removing a startup race in the harness.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>

* fix(multiplayer): never log peer bytes, and keep a fatal server error fatal

Two review findings on the previous commit, both mine to answer for.

`describeError` collapsed whitespace, which is not enough. An error message is
not always a fixed string: `applyAwarenessUpdate` runs `JSON.parse` on the
peer's bytes and V8 quotes ~30 bytes of the offending input back verbatim, ESC
included, so a peer could put terminal escapes and forged content into a log
line. Strip everything outside printable ASCII instead, and say so where the
comment previously claimed the messages were fixed strings.

`wss.on('error')` was worse than the crash it replaced for one case: `ws`
forwards the HTTP server's errors there, so a failed listen (EADDRINUSE) was
logged and the process then exited 0 — a clean shutdown as far as anything
upstream could tell. It now sets a non-zero exit code. Setting `process.exitCode`
rather than calling `process.exit()` keeps the log line from being truncated.

`openClient` in the test helpers now records the socket error it was already
swallowing, so a failed connection reports its cause instead of surfacing as a
bare `waitFor` timeout.

Tests: a malformed awareness frame whose state is `x\x1b[2J OWNED THE LOG` added
to the payload table, with every case now asserting exactly one refusal line and
no control characters in it (1 fail before, 0 after, 3 runs); and a server that
cannot listen must exit non-zero (1 fail before, 0 after, 3 runs). 14/14 on 5
consecutive runs.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>

* test(multiplayer): make the exit-status helper robust to spawn and stdio races

Review follow-ups on runMultiplayerServerUntilExit.

Wait for 'close', not 'exit': 'exit' fires when the child terminates, which can
be before its stdio pipes are drained, and the caller reads the output. On the
EADDRINUSE path the child writes one line and exits immediately after, which is
exactly the shape that loses it.

Listen for 'error' too. A child that fails to spawn emits neither 'exit' nor
'close', so the promise would never settle and the SIGKILL guard could not help.

Report whether the guard fired, rather than leaving the caller to infer it from
the exit signal: `signal` is null for every child exit on Windows, so a server
that hung after the listen error would have looked like one that exited on its
own. The test asserts on that flag instead.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>

* test(multiplayer): assert the refusal line itself, and name hasSyncType for what it takes

Two review nits on the test helpers.

The `doc="..."` assertion searched the whole server log, where CONNECT and
DISCONNECT also name the document, so it would have passed even if the refusal
stopped naming anything. Every assertion about the refusal is now made against
the refusal line, which the test already isolates, and it also checks the peer
is named.

`hasKind` took a sync sub-type but was named as if it took any message kind, and
the two families overlap numerically (`syncStep1 === messageSync === 0`), so a
caller passing the wrong one got a silently wrong answer. No runtime check can
tell aliased numbers apart, so the fix is the name: `hasSyncType`, with the
overlap spelled out where the constants are declared.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>

* test(multiplayer): make the pre-auth tests prove which path they took

The replay test could not establish that its frame went through the pre-auth
buffer: a frame delivered after setup, into the live handler, produces the same
close code and the same refusal line, so if the in-flight margin were ever
missed the test would quietly become a duplicate of the main-loop cases rather
than fail. server.mjs now logs REPLAY when, and only when, it replays a buffered
pre-auth message — worth having on its own, since that path only runs when a
client beat the JWKS fetch on a slow-starting instance — and the test asserts on
it. Removing that log line turns the test red, which is the point.

The socket-error pre-auth test gated on `jwks.requests >= 1`, which the startup
warm-up already satisfies, so it proved nothing about the offender. What makes
it the pre-auth case is that the JWKS response stays parked for the whole test;
it now asserts the server never logged CONNECT, which is exact.

`killedByTimeout` was set before the kill, so a child that exited on its own just
before the timeout — with 'close' still pending on the stdio drain, the very
window this helper waits for — would have been reported as killed. It now claims
the rescue only when there was a live process to signal.

14/14 on eight consecutive runs.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>

* test(multiplayer): document the frame-recording contract in openClient

ws hands every frame over as a Buffer under the default binaryType, text frames
included, so recording them as Uint8Array is lossless for both. Worth stating:
ws 7 delivered text frames as strings, where new Uint8Array(string) would have
been a silent zero-fill, and the difference is not visible at the call site.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>

* test(multiplayer): pin the close code for an illegal frame, and trim comments to the 4-line rule

Both socket-error tests waited for a close and never checked what it was, so an
abrupt 1006 teardown would have passed while the comment beside the payload
claimed 1002. `ws` sends 1002 for an unmasked frame in both the authenticated
and pre-auth cases, confirmed over repeated runs; that is now a named constant
asserted in each test, mirroring malformed_frame.test.mjs. Changing the expected
value turns both red.

The comments added by this branch also ran past the four lines AGENTS.md allows,
and several justified the change to a reader rather than stating the invariant.
Condensed to the invariant, at the site that would break it.

Co-Authored-By: Claude Opus 5.5 (1M context) <noreply@anthropic.com>

---------

Co-authored-by: Claude Opus 5.5 (1M context) <noreply@anthropic.com>
2026-09-25 17:12:47 +02:00

247 lines
8.5 KiB
Bash
Executable File

#!/usr/bin/env bash
#
# Supervision tests for docker/entrypoint-extra.sh.
#
# The real script is run unmodified inside a container, with the four services it
# starts replaced by stubs, so what is under test is the shipped file and the
# shipped bash. The stubs are recognised by the argv the entrypoint uses
# (pyls_launcher.py, server.mjs, dap_debug_service.ts, gateway.mjs), which is
# also what keeps the test honest: change how a service is started and the
# corresponding case here stops matching.
#
# Usage:
# bash docker/test_entrypoint_extra.sh
#
# The image defaults to the base of DockerfileExtra's chain (debian:trixie-slim,
# via windmill-ee-slim), so the bash built-ins behave as they do in the real
# image. Override with ENTRYPOINT_TEST_IMAGE to run it against another one, e.g.
# ENTRYPOINT_TEST_IMAGE=windmill-extra:test bash docker/test_entrypoint_extra.sh
set -euo pipefail
IMAGE="${ENTRYPOINT_TEST_IMAGE:-debian:trixie-slim}"
SCRIPT_DIR="$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)"
ENTRYPOINT="$SCRIPT_DIR/entrypoint-extra.sh"
if ! command -v docker >/dev/null 2>&1; then
echo "docker is required to run this test" >&2
exit 1
fi
WORKDIR="$(mktemp -d)"
trap 'rm -rf "$WORKDIR"' EXIT
# --- the pieces that run inside the container -----------------------------
cat > "$WORKDIR/stub" <<'STUB'
#!/bin/bash
# Stands in for python3 / node / bun. Works out which service it was started as
# from its arguments, then either stays up until it is signalled (recording that
# it was stopped) or exits straight away, to play the crashed service.
name=unknown
for arg in "$@"; do
case "$arg" in
pyls_launcher.py) name=lsp ;;
server.mjs) name=multiplayer ;;
dap_debug_service.ts) name=debugger ;;
gateway.mjs) name=gateway ;;
esac
done
echo "stub[$name] started"
if [ "$name" = "${STUB_IGNORE_TERM:-}" ]; then
# Plays a service that is wedged or slow to honour SIGTERM.
trap 'echo "stub[$name] ignoring SIGTERM"' TERM
else
trap 'echo "stub[$name] got SIGTERM"; touch "/out/$name.stopped"; exit 0' TERM
fi
touch "/out/$name.ready"
if [ "$name" = "${STUB_DIE_AS:-}" ]; then
# Only die once every stub in $STUB_WAIT_FOR has its trap installed. Without
# this the entrypoint can reach its shutdown while a later stub is still
# starting, and that stub takes SIGTERM's default action instead of running
# its handler — a race in the test, not in the entrypoint.
for _ in $(seq 1 600); do
ready=1
for other in ${STUB_WAIT_FOR:-}; do
if [ ! -f "/out/$other.ready" ]; then ready=0; fi
done
if [ "$ready" -eq 1 ]; then break; fi
sleep 0.1
done
echo "stub[$name] exiting with ${STUB_DIE_CODE:-1}"
exit "${STUB_DIE_CODE:-1}"
fi
# `sleep & wait` rather than a bare `sleep`, so the trap runs as soon as the
# signal arrives instead of after the sleep returns. The loop matters: bash
# resumes after an interrupted `wait`, so without it even the trap that only
# logs would fall off the end of the script and exit.
while true; do
sleep 3000 &
wait $!
done
STUB
cat > "$WORKDIR/harness.sh" <<'HARNESS'
#!/bin/bash
# Runs inside the container: installs the stubs, then drives the real
# /entrypoint.sh through each scenario.
set -uo pipefail
mkdir -p /pyls /multiplayer /debugger /out
for tool in python3 node bun; do
cp /harness/stub "/usr/local/bin/$tool"
chmod +x "/usr/local/bin/$tool"
done
export ENABLE_LSP=true ENABLE_MULTIPLAYER=true ENABLE_DEBUGGER=true ENABLE_GATEWAY=true
# Every stub the dying one must see started before it exits.
export STUB_WAIT_FOR="lsp multiplayer debugger gateway"
failures=0
check() {
local what="$1" expected="$2" actual="$3"
if [ "$expected" = "$actual" ]; then
echo " ok: $what is $expected"
else
echo " FAIL: $what: expected $expected, got $actual"
failures=$((failures + 1))
fi
}
check_log() {
local what="$1" pattern="$2"
if grep -qE "$pattern" /out/log; then
echo " ok: $what"
else
echo " FAIL: $what (no line matching /$pattern/)"
failures=$((failures + 1))
fi
}
stopped() {
[ -f "/out/$1.stopped" ] && echo yes || echo no
}
# `wait` on a backgrounded entrypoint, with a watchdog that SIGKILLs it rather
# than letting a wedged shutdown block the run. Sets $wait_status.
wait_bounded() {
local pid="$1" secs="${2:-30}" watchdog
(sleep "$secs"; kill -KILL "$pid" 2>/dev/null) &
watchdog=$!
wait "$pid"
wait_status=$?
kill "$watchdog" 2>/dev/null
wait "$watchdog" 2>/dev/null
}
# Block until the entrypoint has written $1, so no scenario acts on a script that
# has not reached the state it is about to be tested in.
await_log() {
local pattern="$1"
for _ in $(seq 1 600); do
grep -qE "$pattern" /out/log && return 0
sleep 0.1
done
echo " FAIL: timed out waiting for /$pattern/ in the entrypoint log"
failures=$((failures + 1))
return 1
}
echo "== a service that exits takes the container down with it"
rm -rf /out && mkdir -p /out
STUB_DIE_AS=multiplayer STUB_DIE_CODE=3 timeout -k 5 60 bash /entrypoint.sh > /out/log 2>&1
check "exit status" 3 "$?"
cat /out/log
check_log "the dead service is named in the log" 'ERROR: Multiplayer \(PID: [0-9]+\) has exited'
# The survivors were signalled and ran their own shutdown, rather than being left
# running or killed outright.
for name in lsp debugger gateway; do
check "$name stopped cleanly" yes "$(stopped "$name")"
done
echo
echo "== a service that exits 0 is still a failure for the container"
rm -rf /out && mkdir -p /out
STUB_DIE_AS=gateway STUB_DIE_CODE=0 timeout -k 5 60 bash /entrypoint.sh > /out/log 2>&1
check "exit status" 1 "$?"
check_log "the dead service is named in the log" 'ERROR: Gateway \(PID: [0-9]+\) has exited'
echo
echo "== a service that ignores SIGTERM cannot hold the container open"
rm -rf /out && mkdir -p /out
STUB_DIE_AS=multiplayer STUB_DIE_CODE=3 STUB_IGNORE_TERM=lsp SHUTDOWN_GRACE_SECS=2 \
timeout -k 5 60 bash /entrypoint.sh > /out/log 2>&1
check "exit status" 3 "$?"
check_log "the wedged service is killed after the grace period" \
'WARNING: PID [0-9]+ did not stop within 2s, killing it'
check_log "the shutdown still completes" 'All services stopped'
# The ones that do honour SIGTERM still stop the polite way.
for name in debugger gateway; do
check "$name stopped cleanly" yes "$(stopped "$name")"
done
echo
echo "== SIGTERM is still a clean shutdown"
rm -rf /out && mkdir -p /out
bash /entrypoint.sh > /out/log 2>&1 &
entrypoint_pid=$!
if await_log 'All enabled services started'; then
kill -TERM "$entrypoint_pid"
wait_bounded "$entrypoint_pid"
check "exit status" 0 "$wait_status"
for name in lsp multiplayer debugger gateway; do
check "$name stopped cleanly" yes "$(stopped "$name")"
done
else
kill -KILL "$entrypoint_pid" 2>/dev/null
fi
echo
echo "== with no services enabled the entrypoint sleeps instead of exiting"
rm -rf /out && mkdir -p /out
ENABLE_LSP=false ENABLE_MULTIPLAYER=false ENABLE_DEBUGGER=false ENABLE_GATEWAY=false \
bash /entrypoint.sh > /out/log 2>&1 &
entrypoint_pid=$!
if await_log 'Sleeping indefinitely'; then
# Staying up is the correct behaviour here, so there is nothing to wait for
# but the passage of time.
sleep 2
check "still running" yes "$(kill -0 "$entrypoint_pid" 2>/dev/null && echo yes || echo no)"
fi
# SIGKILL, not SIGTERM: this branch blocks in a foreground `sleep infinity`, so
# bash defers the trap until it returns. That is pre-existing behaviour and is
# not what this test is about.
kill -KILL "$entrypoint_pid" 2>/dev/null
wait_bounded "$entrypoint_pid"
echo
if [ "$failures" -eq 0 ]; then
echo "all entrypoint supervision checks passed"
else
echo "$failures check(s) failed"
fi
exit "$failures"
HARNESS
echo "Running entrypoint supervision tests in $IMAGE"
# --entrypoint: the windmill-extra image's own ENTRYPOINT is ["/entrypoint.sh"]
# (docker/DockerfileExtra), which would swallow the command and start the real
# services instead of the harness. Harmless for a plain base image.
DOCKER_RUN=(docker run --rm --init
--entrypoint bash
-v "$ENTRYPOINT:/entrypoint.sh:ro"
-v "$WORKDIR:/harness:ro"
"$IMAGE" /harness/harness.sh)
# Bound the whole run where the host has a `timeout` (GNU coreutils; stock macOS
# ships none), so a stalled image pull cannot hang a CI job. Every scenario
# inside the container is bounded on its own regardless.
if command -v timeout >/dev/null 2>&1; then
timeout "${ENTRYPOINT_TEST_TIMEOUT:-900}" "${DOCKER_RUN[@]}"
else
"${DOCKER_RUN[@]}"
fi