From 5159e0e5e315726ffc20d8890889cf03cf050d86 Mon Sep 17 00:00:00 2001 From: James Ketrenos Date: Tue, 30 Sep 2025 20:57:53 -0700 Subject: [PATCH] Lots of AI tweaks to game. --- .dockerignore | 3 + .env | 5 +- Dockerfile.test | 27 + README.md | 42 +- client/src/App.tsx | 54 +- client/src/Common.ts | 57 +- client/src/HouseRules.tsx | 2 +- docker-compose.yml | 23 + launch.sh | 136 +++- package.json | 15 + server/routes/games.js | 381 ++++++++++-- tools/puppeteer-test/package.json | 11 + tools/puppeteer-test/run_with_server_logs.sh | 51 ++ tools/puppeteer-test/test.js | 623 +++++++++++++++++++ tools/puppeteer-test/tmp_puppeteer.js | 32 + 15 files changed, 1379 insertions(+), 83 deletions(-) create mode 100644 Dockerfile.test create mode 100644 package.json create mode 100644 tools/puppeteer-test/package.json create mode 100755 tools/puppeteer-test/run_with_server_logs.sh create mode 100644 tools/puppeteer-test/test.js create mode 100644 tools/puppeteer-test/tmp_puppeteer.js diff --git a/.dockerignore b/.dockerignore index 7230417..392e916 100644 --- a/.dockerignore +++ b/.dockerignore @@ -1,7 +1,10 @@ * !server/ !client/ +!tools/ +!tools/puppeteer-test/ server/node_modules/ client/node_modules/ !Dockerfile !.env +!Dockerfile.test diff --git a/.env b/.env index ac060c0..ee6a76a 100644 --- a/.env +++ b/.env @@ -2,4 +2,7 @@ VITE_basePath="/ketr.ketran" NODE_CONFIG_ENV='production' VITE_HMR_HOST=battle-linux.ketrenos.com VITE_HMR_PROTOCOL=wss -VITE_HMR_PORT=3001 \ No newline at end of file +VITE_HMR_PORT=3001 +# Compose settings added by assistant +COMPOSE_PROJECT_NAME=peddlers-of-ketran +COMPOSE_FILE=docker-compose.yml diff --git a/Dockerfile.test b/Dockerfile.test new file mode 100644 index 0000000..1318791 --- /dev/null +++ b/Dockerfile.test @@ -0,0 +1,27 @@ +FROM node:20-bullseye + +# Install Chromium and related deps at image build time so test runs are fast +RUN apt-get update \ + && apt-get install -y --no-install-recommends chromium ca-certificates fonts-liberation curl \ + && rm -rf /var/lib/apt/lists/* + +# Avoid puppeteer downloading its own Chromium when using puppeteer-core +ENV PUPPETEER_SKIP_CHROMIUM_DOWNLOAD=true + +# Copy only the puppeteer test folder so we can install deps into the image +WORKDIR /opt/puppeteer-test +# Copy package files (package-lock.json may not exist in workspace) +COPY tools/puppeteer-test/package.json ./ +COPY tools/puppeteer-test/package-lock.json ./ + +# Install dependencies (if package-lock.json missing, npm ci will fail; fall back to npm i) +RUN set -eux; \ + if [ -f package-lock.json ]; then npm ci --no-audit --no-fund --silent; else npm i --no-audit --no-fund --silent; fi + +# Copy the rest of the test files +COPY tools/puppeteer-test/ /opt/puppeteer-test/ + +WORKDIR /opt/puppeteer-test + +# Default entrypoint runs the test; the workspace is mounted by docker-compose +ENTRYPOINT ["node", "test.js"] diff --git a/README.md b/README.md index 54e8c4b..e476f3f 100644 --- a/README.md +++ b/README.md @@ -26,6 +26,30 @@ PRODUCTION=0 ./launch.sh PRODUCTION=1 ./launch.sh ``` +The repository includes a helper script `launch.sh` that wraps `docker compose` with sane defaults for this project. It sets a stable compose project name and the common compose files so you can run commands from the repo root without extra flags. + +Common examples: + +```bash +# Start the development stack (hot-reload client/server) +./launch.sh up + +# Tail logs for the client +./launch.sh logs peddlers-client + +# Show running services +./launch.sh ps + +# Stop everything +./launch.sh down + +# Build images (no cache) +./launch.sh build + +# Start production mode (uses the 'prod' profile) +./launch.sh --production up +``` + #### Development Mode When `PRODUCTION=0`: @@ -48,17 +72,27 @@ The application will be available at `http://localhost:8930`. ### Building (for Production) -If you need to manually build the production image: +If you need to manually build the production image, use the helper which ensures the correct compose files and project name are used: ```bash -docker-compose build +./launch.sh build ``` -This builds the image with server and client dependencies installed and built. +Or using docker compose directly (explicit project and files): + +```bash +docker compose -p peddlers-of-ketran -f docker-compose.yml -f docker-compose.dev.yml build +``` ### Environment Variables -Create a `.env` file in the project root with any required environment variables. The server start script loads these via `export $(cat ../.env | xargs)`. +Create a `.env` file in the project root with any required environment variables. Recommended variables used by the repository tooling: + +- `COMPOSE_PROJECT_NAME` (optional) — project name to be used by `docker compose`. Defaults to `peddlers-of-ketran` in this repo helper. +- `COMPOSE_FILE` (optional) — colon-delimited list of compose files. Example: `docker-compose.yml:docker-compose.dev.yml`. +- `PRODUCTION` — set to `1` for production profile, `0` (or unset) for development. + +The repository already appends these to `.env` for convenience. If you prefer to manage them yourself, remove or edit those lines in `.env`. ## Architecture diff --git a/client/src/App.tsx b/client/src/App.tsx index 20e5b93..c34c7ca 100755 --- a/client/src/App.tsx +++ b/client/src/App.tsx @@ -93,8 +93,7 @@ const Table: React.FC = ({ session }) => { onOpen: () => { console.log(`ws: open`); setError(""); - sendJsonMessage({ type: "game-update" }); - sendJsonMessage({ type: "get", fields }); + // Intentionally only log here; initial messages are sent from an effect }, onError: (err) => { console.log("WebSocket error", err); @@ -112,10 +111,43 @@ const Table: React.FC = ({ session }) => { console.log("readyState:", readyState, "socketUrl:", socketUrl, "ws instance:", getWebSocket()); + // Normalized send: ensure payloads follow { type, data: { ... } } + const normalizedSend = useCallback( + (message: any) => { + if (!sendJsonMessage) return; + // If message is not an object, forward as-is + if (typeof message !== "object" || message === null) { + sendJsonMessage(message); + return; + } + + // If already in the new shape or legacy config shape, forward as-is + if ("data" in message || "config" in message) { + sendJsonMessage(message); + return; + } + + // Normalize: pull type and place remaining fields under `data` + const { type, ...rest } = message; + const payload = rest && Object.keys(rest).length ? rest : {}; + sendJsonMessage({ type, data: payload }); + }, + [sendJsonMessage] + ); + const sendUpdate = (update: unknown) => { - sendJsonMessage(update); + // Use the normalized send wrapper + normalizedSend(update as any); }; + // When the socket opens, request initial game state + useEffect(() => { + if (readyState === ReadyState.OPEN) { + normalizedSend({ type: "game-update" }); + normalizedSend({ type: "get", fields }); + } + }, [readyState, normalizedSend, fields]); + useEffect(() => { if (lastJsonMessage) { const data = lastJsonMessage as any; @@ -131,6 +163,18 @@ const Table: React.FC = ({ session }) => { setWarning(""); }, 3000); break; + case "initial-game": + // New: initial consolidated snapshot from server. Apply as a full + // initial state so the UI can render deterministically for tests. + console.log("Received initial-game snapshot:", data.snapshot); + if (!loaded) { + setLoaded(true); + console.log("App: setLoaded to true (initial-game)"); + } + // Map snapshot fields into the same handler as incremental updates + // for consistency. + data.update = Object.assign({}, data.snapshot); + // fallthrough to handle as a normal game-update case "game-update": console.log("Received game-update:", data.update); if (!loaded) { @@ -191,8 +235,8 @@ const Table: React.FC = ({ session }) => { ws: readyState === ReadyState.OPEN ? getWebSocket() : null, name, gameId, - sendJsonMessage, - }), [readyState, name, gameId, sendJsonMessage]); + sendJsonMessage: normalizedSend, + }), [readyState, name, gameId, normalizedSend]); useEffect(() => { setGlobal(globalValue); diff --git a/client/src/Common.ts b/client/src/Common.ts index 3f4333c..c4c58c4 100644 --- a/client/src/Common.ts +++ b/client/src/Common.ts @@ -11,17 +11,33 @@ function debounce void>(fn: T, ms: number): T { } as T; }; -// Prefer an explicit API base provided via environment variable. This allows -// the client running in a container to talk to the server by docker service -// name (e.g. http://peddlers-of-ketran:8930) while still working when run on -// the host where PUBLIC_URL may be appropriate. -// +// Prefer an explicit API/base provided via environment variable. Different +// deployments and scripts historically used different variable names +// (VITE_API_BASE, VITE_basePath, PUBLIC_URL). Try them in a sensible order +// so the client correctly computes its `base` (router basename and asset +// prefix) regardless of which one is defined. + // Defensive handling: some env consumers or docker-compose YAML authors may // accidentally include literal quotes when setting env vars (for example, // `VITE_API_BASE=""`). That results in the string `""` being present at // runtime and ends up URL-encoded as `%22%22` in fetches. Normalize here so // an accidental quoted-empty value becomes an empty string. -const rawEnvApiBase = import.meta.env.VITE_API_BASE; +const candidateEnvVars = [ + import.meta.env.VITE_API_BASE, + // Some deployments (server-side) set VITE_basePath (note the case). + import.meta.env.VITE_basePath, + // Older scripts or build systems sometimes populate PUBLIC_URL. + import.meta.env.PUBLIC_URL, +]; + +let rawEnvApiBase = ''; +for (const candidate of candidateEnvVars) { + if (typeof candidate === 'string' && candidate.trim() !== '') { + rawEnvApiBase = candidate; + break; + } +} + let envApiBase = typeof rawEnvApiBase === 'string' ? rawEnvApiBase.trim() : ''; // If someone set the literal value '""' or "''", treat it as empty. @@ -48,8 +64,35 @@ if (baseCandidate === '/') { if (baseCandidate.length > 1 && baseCandidate.endsWith('/')) { baseCandidate = baseCandidate.replace(/\/+$/, ''); } + +// Runtime safeguard: when the app is opened at a URL that does not include +// the configured base path (for example, dev server serving at `/` while +// VITE_basePath is `/ketr.ketran`), React Router's +// will refuse to render because the current pathname doesn't start with the +// basename. In that situation prefer to fall back to an empty basename so +// the client still renders correctly in local/dev setups. +try { + if (typeof window !== 'undefined' && baseCandidate) { + const pathname = window.location && window.location.pathname ? window.location.pathname : ''; + // Accept either exact prefix or prefix followed by a slash + if (!(pathname === baseCandidate || pathname.startsWith(baseCandidate + '/'))) { + // Mismatch: fallback to empty base so router can match the URL. + // Keep a console message to aid debugging in browsers. + // eslint-disable-next-line no-console + console.warn(`Configured base '${baseCandidate}' does not match current pathname '${pathname}'; falling back to ''`); + baseCandidate = ''; + } + } +} catch (e) { + /* ignore errors in environments without window */ +} const base = baseCandidate; -const assetsPath = `${base}`; +// Assets are served from the build's `assets` folder. When the app is +// hosted under a base path (e.g. '/ketr.ketran') the actual asset URL is +// '/assets/...'. When there's no base, assets are available at +// '/assets/...'. Compute `assetsPath` accordingly so runtime URLs match +// build-time expectations. +const assetsPath = base === '' ? '/assets' : `${base}/assets`; const gamesPath = `${base}`; export { base, debounce, assetsPath, gamesPath }; \ No newline at end of file diff --git a/client/src/HouseRules.tsx b/client/src/HouseRules.tsx index 2bfec53..aa40278 100644 --- a/client/src/HouseRules.tsx +++ b/client/src/HouseRules.tsx @@ -584,7 +584,7 @@ const HouseRules: React.FC = ({ checked={checked} id={item.key} onChange={(e) => setRule(e, item.key)} - disabled={gameState !== "lobby" || !name} + disabled={gameState !== "lobby"} /> diff --git a/docker-compose.yml b/docker-compose.yml index 2a1a377..7e5d647 100644 --- a/docker-compose.yml +++ b/docker-compose.yml @@ -67,6 +67,29 @@ services: networks: - peddlers-network + peddlers-test: + profiles: [dev,test] + container_name: ketr.test + build: + context: . + dockerfile: Dockerfile.test + working_dir: /opt/puppeteer-test + # Mount the workspace so test artifacts (screenshots) are written back to host + volumes: + - ./:/workspace:rw + - ./tools/puppeteer-test:/opt/puppeteer-test:rw + - /dev/shm:/dev/shm + environment: + # Default to the client service hostname on the compose network so tests + # can reach the dev client without using host networking. + - TEST_URL=https://peddlers-client:3001/ketr.ketran/ + - CHROME_PATH=/usr/bin/chromium + entrypoint: ["/bin/sh", "-c", "echo Waiting for $${TEST_URL:-https://localhost:3001/ketr.ketran/} to be reachable && \ + for i in $(seq 1 10); do if curl -k -sSf $${TEST_URL:-https://localhost:3001/ketr.ketran/} >/dev/null 2>&1; then echo url up; break; else echo waiting...; sleep 0.5; fi; done; \ + node test.js $${TEST_URL:-https://localhost:3001/ketr.ketran/}"] + networks: + - peddlers-network + networks: peddlers-network: driver: bridge diff --git a/launch.sh b/launch.sh index 285b473..49b560d 100755 --- a/launch.sh +++ b/launch.sh @@ -1,37 +1,72 @@ -#!/bin/bash +#!/usr/bin/env bash +set -euo pipefail -# Launch script for Peddlers of Ketran -# Set PRODUCTION=1 for production mode, PRODUCTION=0 or unset for development mode +# launch.sh - helper wrapper around `docker compose` for this repo +# +# Features: +# - sets a stable Compose project name (defaults to peddlers-of-ketran) +# - supports multiple compose files (docker-compose.yml and docker-compose.dev.yml) +# - convenience commands: up, down, restart, ps, logs, build +# - supports --production to switch profiles -# Default values +DIR="$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)" + +# Default values (can be overridden by environment or .env) +PROJECT_NAME="${COMPOSE_PROJECT_NAME:-peddlers-of-ketran}" +COMPOSE_FILES="${COMPOSE_FILE:-docker-compose.yml:docker-compose.dev.yml}" PRODUCTION=${PRODUCTION:-0} COMMAND="up" +SERVICE="" -# Parse arguments +usage() { + cat </dev/null 2>&1; then + DOCKER_COMPOSE_CMD=(docker compose) +elif command -v docker-compose >/dev/null 2>&1; then + DOCKER_COMPOSE_CMD=(docker-compose) +else + echo "Error: neither 'docker compose' nor 'docker-compose' is available on PATH." + exit 1 +fi + +compose_base=("${DOCKER_COMPOSE_CMD[@]}" -p "$PROJECT_NAME" "${FILES_ARGS[@]}") + +echo "Using compose project: $PROJECT_NAME" +echo "Compose files: ${FILES_ARGS[*]}" + case "$COMMAND" in up) - echo "Bringing containers up (detached)..." - docker compose --profile "$PROFILE" up -d + echo "Bringing containers up (detached) with profile '$PROFILE'..." + "${compose_base[@]}" --profile "$PROFILE" up -d ;; down) - echo "Bringing containers down..." - docker compose --profile "$PROFILE" down + echo "Querying compose-managed containers for project '$PROJECT_NAME'..." + # Show containers that will be affected so users know what's being removed + "${compose_base[@]}" ps --services --quiet || true + echo "Bringing containers down (profile: $PROFILE)..." + "${compose_base[@]}" --profile "$PROFILE" down --remove-orphans ;; restart) - echo "Restarting containers..." - docker compose --profile "$PROFILE" down - docker compose --profile "$PROFILE" up -d + echo "Restarting containers (down + up -d) with profile '$PROFILE'..." + "${compose_base[@]}" --profile "$PROFILE" down --remove-orphans + "${compose_base[@]}" --profile "$PROFILE" up -d + ;; + ps) + echo "Compose ps for project '$PROJECT_NAME'" + "${compose_base[@]}" ps + ;; + logs) + echo "Tailing logs for project '$PROJECT_NAME'${SERVICE:+, service: $SERVICE}" + if [ -n "$SERVICE" ]; then + "${compose_base[@]}" logs -f --tail=200 "$SERVICE" + else + "${compose_base[@]}" logs -f --tail=200 + fi + ;; + build) + echo "Building images for project '$PROJECT_NAME'${SERVICE:+, service: $SERVICE}" + if [ -n "$SERVICE" ]; then + "${compose_base[@]}" build --no-cache "$SERVICE" + else + "${compose_base[@]}" build --no-cache + fi ;; *) echo "Unknown command: $COMMAND" - echo "Usage: $0 [--production] [up|down|restart]" + usage exit 1 ;; -esac \ No newline at end of file +esac diff --git a/package.json b/package.json new file mode 100644 index 0000000..d13be29 --- /dev/null +++ b/package.json @@ -0,0 +1,15 @@ +{ + "name": "workspace", + "version": "1.0.0", + "description": "This project consists of both the front-end React client and back-end Node.js game API server for the Settlers of Catan-style board game.", + "main": "tmp_puppeteer.js", + "scripts": { + "test": "echo \"Error: no test specified\" && exit 1" + }, + "keywords": [], + "author": "", + "license": "ISC", + "dependencies": { + "puppeteer": "^20.9.0" + } +} diff --git a/server/routes/games.js b/server/routes/games.js index 57a3426..f31aca1 100755 --- a/server/routes/games.js +++ b/server/routes/games.js @@ -26,6 +26,32 @@ const debug = { update: false }; +// Normalize incoming websocket messages to a canonical { type, data } +// shape. Some clients historically sent the payload as { type, data } while +// others used a flatter shape. This helper accepts either a string or an +// already-parsed object and returns a stable object so handlers don't need +// to defensively check multiple nested locations. +function normalizeIncoming(msg) { + if (!msg) return { type: null, data: null }; + let parsed = null; + try { + if (typeof msg === 'string') { + parsed = JSON.parse(msg); + } else { + parsed = msg; + } + } catch (e) { + // if parsing failed, return nulls so the caller can log/ignore + return { type: null, data: null }; + } + if (!parsed) return { type: null, data: null }; + const type = parsed.type || parsed.action || null; + // Prefer parsed.data when present, but allow flattened payloads where + // properties like `name` live at the root. + const data = parsed.data || (Object.keys(parsed).length ? Object.assign({}, parsed) : null); + return { type, data }; +} + let gameDB; require("../db/games").then(function(db) { @@ -159,7 +185,7 @@ const processGameOrder = (game, player, dice) => { setForSettlementPlacement(game, getValidCorners(game)); addActivity(game, null, `${game.robberName} Robber Robinson entered the scene as the nefarious robber!`); addChatMessage(game, null, `Initial settlement placement has started!`); - addChatMessage(game, null, `It is ${game.turn.name}'s turn to place a settlement.`);4 + addChatMessage(game, null, `It is ${game.turn.name}'s turn to place a settlement.`); sendUpdateToPlayers(game, { players: getFilteredPlayers(game), @@ -616,7 +642,18 @@ const loadGame = async (id) => { } if (id in games) { - return games[id]; + // If we have a cached game in memory, ensure any ephemeral flags that + // control per-session lifecycle (like _initialSnapshotSent) are cleared + // so that a newly attached websocket will receive the consolidated + // initial snapshot. This is important for long-running dev servers + // where the in-memory cache may persist between reconnects. + const cached = games[id]; + for (let sid in cached.sessions) { + if (cached.sessions[sid] && cached.sessions[sid]._initialSnapshotSent) { + delete cached.sessions[sid]._initialSnapshotSent; + } + } + return cached; } let game = await readFile(`/db/games/${id}`) @@ -675,6 +712,11 @@ const loadGame = async (id) => { } session.live = false; + // Ensure we treat initial snapshot as unsent on (re)load so new socket + // attachments will get a fresh 'initial-game' message. + if (session._initialSnapshotSent) { + delete session._initialSnapshotSent; + } /* Populate the 'unselected' list from the session table */ if (!game.sessions[id].color && game.sessions[id].name) { @@ -3279,7 +3321,14 @@ const wsInactive = (game, req) => { if (session && session.ws) { console.log(`Closing WebSocket to ${session.name} due to inactivity.`); - session.ws.close(); + try { + // Defensive: close only if a socket exists; swallow any errors from closing + if (session.ws) { + try { session.ws.close(); } catch (e) { /* ignore close errors */ } + } + } catch (e) { + /* ignore */ + } session.ws = undefined; } @@ -3439,6 +3488,10 @@ const saveGame = async (game) => { if (reduced.keepAlive) { delete reduced.keepAlive; } + // Do not persist ephemeral test/runtime-only flags + if (reduced._initialSnapshotSent) { + delete reduced._initialSnapshotSent; + } reducedGame.sessions[id] = reduced; @@ -3501,6 +3554,68 @@ const all = `[ all ]`; const info = `[ info ]`; const todo = `[ todo ]`; +/* Per-session send throttle (milliseconds). Coalesce rapid updates to avoid + * tight send loops that can overwhelm clients. If multiple updates are + * enqueued within the throttle window, the latest one replaces prior pending + * updates so the client receives a single consolidated message. */ +const SEND_THROTTLE_MS = 50; + +const queueSend = (session, message) => { + if (!session || !session.ws) return; + try { + const now = Date.now(); + if (!session._lastSent) session._lastSent = 0; + const elapsed = now - session._lastSent; + // If the exact same message was sent last time and nothing is pending, + // skip sending to avoid pointless duplicate traffic. + if (!session._pendingTimeout && session._lastMessage === message) { + return; + } + + // If we haven't sent recently and there's no pending timer, send now + if (elapsed >= SEND_THROTTLE_MS && !session._pendingTimeout) { + try { + session.ws.send(message); + session._lastSent = Date.now(); + session._lastMessage = message; + } catch (e) { + console.warn(`${session.id}: queueSend immediate send failed:`, e); + } + return; + } + + // Otherwise, store latest message and schedule a send + // If the pending message would equal the last-sent message, don't bother + // storing/scheduling it. + if (session._lastMessage === message) { + return; + } + session._pendingMessage = message; + if (session._pendingTimeout) { + // already scheduled; newest message will be sent when timer fires + return; + } + const delay = Math.max(1, SEND_THROTTLE_MS - elapsed); + session._pendingTimeout = setTimeout(() => { + try { + if (session.ws && session._pendingMessage) { + session.ws.send(session._pendingMessage); + session._lastSent = Date.now(); + session._lastMessage = session._pendingMessage; + } + } catch (e) { + console.warn(`${session.id}: queueSend delayed send failed:`, e); + } + // clear pending fields + session._pendingMessage = undefined; + clearTimeout(session._pendingTimeout); + session._pendingTimeout = undefined; + }, delay); + } catch (e) { + console.warn(`${session.id}: queueSend exception:`, e); + } +}; + const sendGameToPlayer = (game, session) => { console.log(`${session.id}: -> sendGamePlayer:${getName(session)} - full game`); if (!session.ws) { @@ -3518,10 +3633,11 @@ const sendGameToPlayer = (game, session) => { update = getFilteredGameForPlayer(game, session); } - session.ws.send(JSON.stringify({ - type: 'game-update', + const message = JSON.stringify({ + type: 'game-update', update: update - })); + }); + queueSend(session, message); }; const sendGameToPlayers = (game) => { @@ -3573,7 +3689,7 @@ const sendUpdateToPlayers = async (game, update) => { console.log(`${session.id}: -> sendUpdateToPlayers: ` + `Currently no connection.`); } else { - session.ws.send(message); + queueSend(session, message); } } } @@ -3613,7 +3729,7 @@ const sendUpdateToPlayer = async (game, session, update) => { console.log(`${session.id}: -> sendUpdateToPlayer: ` + `Currently no connection.`); } else { - session.ws.send(message); + queueSend(session, message); } } @@ -3829,7 +3945,29 @@ const gotoLobby = (game, session) => { router.ws("/ws/:id", async (ws, req) => { if (!req.cookies || !req.cookies.player) { - ws.send(JSON.stringify({ type: 'error', error: `Unable to find session cookie` })); + // If the client hasn't established a session cookie, they cannot + // participate in a websocket-backed game session. Log the request + // headers to aid debugging (e.g. missing Cookie header due to + // cross-site requests or proxy configuration) and close the socket + // with a sensible code so the client sees a deterministic close. + try { + const remote = req.ip || (req.headers && (req.headers['x-forwarded-for'] || req.connection && req.connection.remoteAddress)) || 'unknown'; + console.warn(`[ws] Rejecting connection from ${remote} - missing session cookie. headers=${JSON.stringify(req.headers || {})}`); + } catch (e) { + console.warn('[ws] Rejecting connection - missing session cookie (unable to serialize headers)'); + } + try { + // Inform the client why we are closing, then close the socket. + ws.send(JSON.stringify({ type: 'error', error: `Unable to find session cookie` })); + } catch (e) { + /* ignore send errors */ + } + try { + // 1008 = Policy Violation - appropriate for missing auth cookie + ws.close && ws.close(1008, 'Missing session cookie'); + } catch (e) { + /* ignore close errors */ + } return; } @@ -3850,23 +3988,31 @@ router.ws("/ws/:id", async (ws, req) => { /* Setup WebSocket event handlers prior to performing any async calls or * we may miss the first messages from clients */ ws.on('error', async (event) => { - console.error(`WebSocket error: `, event.message); + console.error(`WebSocket error: `, event && event.message ? event.message : event); const game = await loadGame(gameId); if (!game) { return; } const session = getSession(game, req.cookies.player); session.live = false; - if (session.ws) { - session.ws.close(); - session.ws = undefined; + try { + console.log(`${short}: ws.on('error') - session.ws === ws? ${session.ws === ws}`); + console.log(`${short}: ws.on('error') - session.id=${session && session.id}`); + console.log(`${short}: ws.on('error') - stack:`, new Error().stack); + // Only close the session.ws if it is the same socket that errored. + if (session.ws && session.ws === ws) { + try { session.ws.close(); } catch (e) { console.warn(`${short}: error while closing session.ws:`, e); } + session.ws = undefined; + } + } catch (e) { + console.warn(`${short}: exception in ws.on('error') handler:`, e); } departLobby(game, session); }); ws.on('close', async (event) => { - console.log(`${short} - closed connection`); + console.log(`${short} - closed connection (event: ${event && typeof event === 'object' ? JSON.stringify(event) : event})`); const game = await loadGame(gameId); if (!game) { @@ -3875,16 +4021,23 @@ router.ws("/ws/:id", async (ws, req) => { const session = getSession(game, req.cookies.player); if (session.player) { session.player.live = false; - } + } session.live = false; - if (session.ws) { + // Only cleanup the session.ws if it references the same socket object + try { + console.log(`${short}: ws.on('close') - session.ws === ws? ${session.ws === ws}`); + console.log(`${short}: ws.on('close') - session.id=${session && session.id}, lastActive=${session && session.lastActive}`); + if (session.ws && session.ws === ws) { /* Cleanup any voice channels */ - if (id in audio) { - part(audio[id], session); + if (id in audio) { + try { part(audio[id], session); } catch (e) { console.warn(`${short}: Error during part():`, e); } + } + try { session.ws.close(); } catch (e) { console.warn(`${short}: error while closing session.ws in on('close'):`, e); } + session.ws = undefined; + console.log(`${short}:WebSocket closed for ${getName(session)}`); } - session.ws.close(); - session.ws = undefined; - console.log(`${short}:WebSocket closed for ${getName(session)}`); + } catch (e) { + console.warn(`${short}: exception in ws.on('close') handler:`, e); } departLobby(game, session); @@ -3908,7 +4061,13 @@ router.ws("/ws/:id", async (ws, req) => { }); for (let id in game.sessions) { if (game.sessions[id].ws) { - game.sessions[id].ws.close(); + try { + console.log(`${short}: Removing game - closing session ${id} socket (game removal cleanup)`); + console.log(`${short}: Closing socket stack:`, new Error().stack); + game.sessions[id].ws.close(); + } catch (e) { + console.warn(`${short}: error closing session socket during game removal:`, e); + } delete game.sessions[id]; } } @@ -3924,18 +4083,37 @@ router.ws("/ws/:id", async (ws, req) => { }); ws.on('message', async (message) => { - let data; - try { - data = JSON.parse(message); - } catch (error) { - console.error(`${all}: parse error`, message); + // Normalize the incoming message to { type, data } so handlers can + // reliably access the payload without repeated defensive checks. + const incoming = normalizeIncoming(message); + if (!incoming.type) { + // If we couldn't parse or determine the type, log and ignore the + // message to preserve previous behavior. + try { + console.error(`${all}: parse/normalize error`, message); + } catch (e) { + console.error('parse/normalize error'); + } return; } + const data = incoming.data; const game = await loadGame(gameId); const session = getSession(game, req.cookies.player); - if (!session.ws) { - session.ws = ws; + // Keep track of any previously attached websocket so we can detect + // first-time attaches and websocket replacements (reconnects). + const previousWs = session.ws; + const wasAttached = !!previousWs; + // If there was a previous websocket and it's a different object, try to + // close it to avoid stale sockets lingering in memory. + if (previousWs && previousWs !== ws) { + try { + previousWs.close(); + } catch (e) { + /* ignore close errors */ + } } + // Attach the current websocket for this session. + session.ws = ws; if (session.player) { session.player.live = true; } @@ -3943,10 +4121,24 @@ router.ws("/ws/:id", async (ws, req) => { session.lastActive = Date.now(); let error, warning, update, processed = true; + + // If this is the first time the session attached a WebSocket, or if the + // websocket was just replaced (reconnect), send an initial consolidated + // snapshot so clients can render deterministically without needing to + // wait for a flurry of incremental game-update events. + if (!session._initialSnapshotSent) { + try { + sendInitialGameSnapshot(game, session); + session._initialSnapshotSent = true; + } catch (e) { + console.error(`${session.id}: error sending initial snapshot`, e); + } + } - switch (data.type) { + switch (incoming.type) { case 'join': - join(audio[id], session, data.config); + // Accept either legacy `config` or newer `data` field from clients + join(audio[id], session, data.config || data.data || {}); break; case 'part': @@ -3959,10 +4151,11 @@ router.ws("/ws/:id", async (ws, req) => { return; } - const { peer_id, candidate } = data.config; - if (debug.audio) console.log(`${short}:${id} <- relayICECandidate ${getName(session)} to ${peer_id}`, - candidate); - + // Support both { config: {...} } and { data: {...} } client payloads + const cfg = data.config || data.data || {}; + const { peer_id, candidate } = cfg; + if (debug.audio) console.log(`${short}:${id} <- relayICECandidate ${getName(session)} to ${peer_id}`, candidate); + message = JSON.stringify({ type: 'iceCandidate', data: {'peer_id': getName(session), 'candidate': candidate } @@ -3978,9 +4171,11 @@ router.ws("/ws/:id", async (ws, req) => { console.error(`${id} - relaySessionDescription - Does not have Audio`); return; } - const { peer_id, session_description } = data.config; - if (debug.audio) console.log(`${short}:${id} - relaySessionDescription ${getName(session)} to ${peer_id}`, - session_description); + + // Support both { config: {...} } and { data: {...} } client payloads + const cfg = data.config || data.data || {}; + const { peer_id, session_description } = cfg; + if (debug.audio) console.log(`${short}:${id} - relaySessionDescription ${getName(session)} to ${peer_id}`, session_description); message = JSON.stringify({ type: 'sessionDescription', data: {'peer_id': getName(session), 'session_description': session_description } @@ -3999,9 +4194,42 @@ router.ws("/ws/:id", async (ws, req) => { sendGameToPlayer(game, session); break; + case 'peer_state_update': { + // Broadcast a peer state update (muted/video_on) to other peers in the game audio map + if (!(id in audio)) { + console.error(`${session.id}:${id} <- peer_state_update - Does not have Audio`); + return; + } + + const cfg = data.config || data.data || {}; + const { peer_id, muted, video_on } = cfg; + if (!session.name) { + console.error(`${session.id}: peer_state_update - unnamed session`); + return; + } + + const messagePayload = JSON.stringify({ + type: 'peer_state_update', + data: { peer_id: session.name, muted, video_on }, + }); + + // Send to all other peers + for (const other in audio[id]) { + if (other === session.name) continue; + try { + audio[id][other].ws.send(messagePayload); + } catch (e) { + console.warn(`Failed sending peer_state_update to ${other}:`, e); + } + } + } break; + case 'player-name': - console.log(`${short}: <- player-name:${getName(session)} - setPlayerName - ${data.name}`) - error = setPlayerName(game, session, data.name); + // Support both legacy { type: 'player-name', name: 'Foo' } + // and normalized { type: 'player-name', data: { name: 'Foo' } } + const _pname = (data && data.name) || (data && data.data && data.data.name); + console.log(`${short}: <- player-name:${getName(session)} - setPlayerName - ${_pname}`) + error = setPlayerName(game, session, _pname); if (error) { sendError(session, error); }else { @@ -4036,9 +4264,17 @@ router.ws("/ws/:id", async (ws, req) => { break; case 'get': - console.log(`${short}: <- get:${getName(session)} ${data.fields.join(',')}`); + // Guard against clients that send a 'get' without fields. + // Support both legacy shape: { type: 'get', fields: [...] } + // and normalized shape: { type: 'get', data: { fields: [...] } } + const requestedFields = Array.isArray(data.fields) + ? data.fields + : (data.data && Array.isArray(data.data.fields)) + ? data.data.fields + : []; + console.log(`${short}: <- get:${getName(session)} ${requestedFields.length ? requestedFields.join(',') : ''}`); update = {}; - data.fields.forEach((field) => { + requestedFields.forEach((field) => { switch (field) { case 'player': sendWarning(session, `'player' is not a valid item. use 'private' instead`); @@ -4152,7 +4388,7 @@ router.ws("/ws/:id", async (ws, req) => { processed = true; const priorSession = session; - switch (data.type) { + switch (incoming.type) { case 'roll': console.log(`${short}: <- roll:${getName(session)}`); warning = roll(game, session); @@ -4345,6 +4581,17 @@ router.ws("/ws/:id", async (ws, req) => { } session.live = true; session.lastActive = Date.now(); + // Ensure we only attempt to send the consolidated initial snapshot once + // per session lifecycle. Tests and clients expect a single 'initial-game' + // message when a socket first attaches. + if (!session._initialSnapshotSent) { + try { + sendInitialGameSnapshot(game, session); + session._initialSnapshotSent = true; + } catch (e) { + console.error(`${session.id}: error sending initial snapshot on connect`, e); + } + } if (session.name) { sendUpdateToPlayers(game, { players: getFilteredPlayers(game), @@ -4448,7 +4695,6 @@ const getFilteredGameForPlayer = (game, session) => { return Object.assign(reducedGame, { live: true, - timestamp: Date.now(), status: session.error ? session.error : "success", name: session.name, color: session.color, @@ -4460,6 +4706,34 @@ const getFilteredGameForPlayer = (game, session) => { }); } +/** + * Send a consolidated initial snapshot to a single session. + * This is used to allow clients (and tests) to render the full + * game state deterministically on first attach instead of having + * to wait for many incremental `game-update` messages. + */ +const sendInitialGameSnapshot = (game, session) => { + try { + const snapshot = getFilteredGameForPlayer(game, session); + const message = JSON.stringify({ type: 'initial-game', snapshot }); + // Small debug log to help test harnesses detect that the server sent + // the consolidated snapshot. Keep output small to avoid noisy logs. + try { + const topKeys = Object.keys(snapshot || {}).slice(0, 10).join(','); + console.log(`${session.id}: sending initial-game snapshot keys: ${topKeys}`); + } catch (e) { + /* ignore logging errors */ + } + if (session && session.ws && session.ws.send) { + session.ws.send(message); + } else { + console.warn(`${session.id}: Unable to send initial snapshot - no websocket available`); + } + } catch (err) { + console.error(`${session.id}: error in sendInitialGameSnapshot`, err); + } +} + /* Example: "stolen": { "robber": { @@ -4794,7 +5068,16 @@ router.get("/", (req, res/*, next*/) => { let playerId; if (!req.cookies.player) { playerId = crypto.randomBytes(16).toString('hex'); - res.cookie('player', playerId); + // Determine whether this request is secure so we can set cookie flags + // appropriately. In production behind TLS we want SameSite=None and + // Secure so the cookie is sent on cross-site websocket connects. + const secure = req.secure || (req.headers && req.headers['x-forwarded-proto'] === 'https') || process.env.NODE_ENV === 'production'; + const cookieOpts = { + httpOnly: false, + sameSite: secure ? 'none' : 'lax', + secure: !!secure + }; + res.cookie('player', playerId, cookieOpts); } else { playerId = req.cookies.player; } @@ -4812,7 +5095,13 @@ router.post("/:id?", async (req, res/*, next*/) => { let playerId; if (!req.cookies.player) { playerId = crypto.randomBytes(16).toString('hex'); - res.cookie('player', playerId); + const secure = req.secure || (req.headers && req.headers['x-forwarded-proto'] === 'https') || process.env.NODE_ENV === 'production'; + const cookieOpts = { + httpOnly: false, + sameSite: secure ? 'none' : 'lax', + secure: !!secure + }; + res.cookie('player', playerId, cookieOpts); } else { playerId = req.cookies.player; } diff --git a/tools/puppeteer-test/package.json b/tools/puppeteer-test/package.json new file mode 100644 index 0000000..432c15e --- /dev/null +++ b/tools/puppeteer-test/package.json @@ -0,0 +1,11 @@ +{ + "name": "peddlers-puppeteer-test", + "version": "0.0.0", + "private": true, + "scripts": { + "test": "node test.js" + }, + "dependencies": { + "puppeteer-core": "^20.0.0" + } +} diff --git a/tools/puppeteer-test/run_with_server_logs.sh b/tools/puppeteer-test/run_with_server_logs.sh new file mode 100755 index 0000000..58cf2b9 --- /dev/null +++ b/tools/puppeteer-test/run_with_server_logs.sh @@ -0,0 +1,51 @@ +#!/usr/bin/env bash +set -euo pipefail + +# Run the peddlers-test harness while streaming the server container logs to +# a timestamped file in the repo root. This helps correlate client-side +# intercepted WS sends with server handling (e.g., setPlayerName lines). + +TS=$(date +%s) +OUT_DIR=$(pwd) +LOGFILE="$OUT_DIR/tmp-server-logs-$TS.server.log" +echo "ts=$TS" + +# Find the server container by common names used in docker-compose +CID=$(docker ps -q --filter "name=ketr.ketran.dev" || true) +if [ -z "$CID" ]; then CID=$(docker ps -q --filter "name=ketr.ketran" || true); fi +if [ -z "$CID" ]; then + # fallback: try to find the compose service container + CID=$(docker compose -f docker-compose.yml ps -q peddlers-of-ketran || true) +fi +echo "server container id: ${CID:-}" + +LOG_PID="" +if [ -n "$CID" ]; then + echo "Starting log follower: docker logs -f $CID -> $LOGFILE" + # Stream logs (since 0s to include recent lines) in background + docker logs --since 0s -f "$CID" > "$LOGFILE" 2>&1 & + LOG_PID=$! + echo "log follower pid: $LOG_PID" +else + echo "Warning: no server container found; server logs will not be captured" +fi + +cleanup() { + rc=$? + if [ -n "$LOG_PID" ]; then + echo "Stopping log follower pid $LOG_PID" + kill "$LOG_PID" 2>/dev/null || true + wait "$LOG_PID" 2>/dev/null || true + fi + echo "Artifacts in repo root (tmp-*)" + ls -la tmp-* 2>/dev/null || true + exit $rc +} + +trap cleanup EXIT INT TERM + +echo "Running harness (docker compose run --rm -e TEST_MAX_MS=20000 peddlers-test)" +# Run the test harness inside compose; let it run with the env override for a short test +docker compose -f docker-compose.yml run --rm -e TEST_MAX_MS=20000 peddlers-test + +echo "Harness completed; cleanup will run via trap" diff --git a/tools/puppeteer-test/test.js b/tools/puppeteer-test/test.js new file mode 100644 index 0000000..15992d4 --- /dev/null +++ b/tools/puppeteer-test/test.js @@ -0,0 +1,623 @@ +const puppeteer = require("puppeteer-core"); +const fs = require("fs"); + +(async () => { + const t0 = Date.now(); + const ts = () => new Date().toISOString() + " +" + (Date.now() - t0) + "ms"; + const log = (...args) => console.log(ts(), ...args); + log("Puppeteer test starting"); + let browser; + // Global timeout (ms) for the whole test run to avoid infinite log floods. + const MAX_TEST_MS = parseInt(process.env.TEST_MAX_MS || "60000", 10); + let _globalTimeout = null; + let _timedOut = false; + const startGlobalTimeout = () => { + if (_globalTimeout) return; + _globalTimeout = setTimeout(async () => { + _timedOut = true; + try { + log(`Global timeout of ${MAX_TEST_MS}ms reached — aborting test`); + if (browser) { + try { + await browser.close(); + log('Browser closed due to global timeout'); + } catch (e) { + log('Error while closing browser on timeout:', e && e.message ? e.message : e); + } + } + } catch (e) { + // swallow + } + // Exit with distinct code so CI can tell a timeout occurred. + process.exit(124); + }, MAX_TEST_MS); + }; + const clearGlobalTimeout = () => { + try { + if (_globalTimeout) clearTimeout(_globalTimeout); + } catch (e) {} + _globalTimeout = null; + }; + // Start the global timeout immediately so the whole test run (including + // browser launch) is bounded by TEST_MAX_MS. This makes the timeout work + // even when env vars are not propagated the way the caller expects. + startGlobalTimeout(); + try { + // Try to use a system Chrome/Chromium binary if present. This lets + // developers skip downloading Chromium during `npm install` by setting + // PUPPETEER_SKIP_CHROMIUM_DOWNLOAD=1 and supplying CHROME_PATH. + const possiblePaths = []; + if (process.env.CHROME_PATH) possiblePaths.push(process.env.CHROME_PATH); + possiblePaths.push( + "/usr/bin/google-chrome-stable", + "/usr/bin/google-chrome", + "/usr/bin/chromium-browser", + "/usr/bin/chromium" + ); + let launchOptions = { + args: ["--no-sandbox", "--disable-setuid-sandbox"], + ignoreHTTPSErrors: true, + }; + for (const p of possiblePaths) { + try { + const stat = require("fs").statSync(p); + if (stat && stat.isFile()) { + log("Found system Chrome at", p, "— will use it"); + launchOptions.executablePath = p; + break; + } + } catch (e) { + // ignore + } + } + + log( + "Launching Puppeteer with options:", + Object.assign({}, launchOptions, { + executablePath: launchOptions.executablePath + ? launchOptions.executablePath + : "", + }) + ); + const tLaunch = Date.now(); + browser = await puppeteer.launch(launchOptions); + log("Browser launched (took", Date.now() - tLaunch + "ms)"); + // Start the global timeout after browser is launched so we can reliably + // close the browser if we need to abort. + startGlobalTimeout(); + const page = await browser.newPage(); + log("New page created"); + + // Intercept WebSocket.prototype.send as early as possible so we can + // capture outgoing messages from the client (helps verify the name + // submit handler triggered). Use evaluateOnNewDocument so interception + // is in place before any page script runs. + try { + await page.evaluateOnNewDocument(() => { + try { + const orig = WebSocket.prototype.send; + WebSocket.prototype.send = function (data) { + try { + window.__wsSends = window.__wsSends || []; + let d = data; + // Handle ArrayBuffer or typed arrays by attempting to decode + if (d instanceof ArrayBuffer || ArrayBuffer.isView(d)) { + try { + d = new TextDecoder().decode(d); + } catch (e) { + d = '' + d; + } + } + const entry = { ts: Date.now(), data: typeof d === 'string' ? d : (d && d.toString ? d.toString() : JSON.stringify(d)) }; + window.__wsSends.push(entry); + // Emit a console log so the host log captures the message body + try { console.log('WS_SEND_INTERCEPT', entry.data); } catch (e) {} + } catch (e) { + // swallow + } + return orig.apply(this, arguments); + }; + } catch (e) { + // swallow + } + }); + log('Installed WebSocket send interceptor (evaluateOnNewDocument)'); + } catch (e) { + log('Could not install WS interceptor:', e && e.message ? e.message : e); + } + + // forward page console messages to our logs (helpful to see runtime errors) + page.on('console', msg => { + try { + const args = msg.args ? msg.args.map(a => a.toString()).join(' ') : msg.text(); + log('PAGE_CONSOLE', msg.type(), args); + } catch (e) { + log('PAGE_CONSOLE', msg.type(), msg.text()); + } + }); + page.on('requestfailed', req => { + try { log('REQUEST_FAILED', req.url(), req.failure && req.failure().errorText); } catch (e) { log('REQUEST_FAILED', req.url()); } + }); + + // track simple network counts so we can see if navigation triggers many requests + let reqCount = 0, + resCount = 0; + page.on("request", (r) => { + reqCount++; + }); + page.on("response", (r) => { + resCount++; + }); + + // small helper to replace the deprecated page.waitForTimeout + const sleep = (ms) => new Promise((res) => setTimeout(res, ms)); + + // Navigate to the dev client; allow overriding via CLI or env + const url = + process.argv[2] || + process.env.TEST_URL || + "https://localhost:3001/ketr.ketran/"; + log("Navigating to", url); + try { + log("Calling page.goto (domcontentloaded, 10s timeout)"); + const tNavStart = Date.now(); + await page.goto(url, { waitUntil: "domcontentloaded", timeout: 10000 }); + log( + "Page load (domcontentloaded) finished (took", + Date.now() - tNavStart + "ms)", + "requests=", + reqCount, + "responses=", + resCount + ); + + // Diagnostic snapshot: save the full HTML and a screenshot immediately + // after domcontentloaded so we can inspect the initial page state even + // when the inputs appear much later. + try { + const domContent = await page.content(); + try { + fs.writeFileSync('/workspace/tmp-domcontent.html', domContent); + log('Saved domcontent HTML to /workspace/tmp-domcontent.html (length', domContent.length + ')'); + } catch (e) { + log('Failed to write domcontent HTML:', e && e.message ? e.message : e); + } + } catch (e) { + log('Could not read page content at domcontentloaded:', e && e.message ? e.message : e); + } + try { + const shotNow = '/workspace/tmp-domcontent.png'; + await page.screenshot({ path: shotNow, fullPage: true }); + log('Saved domcontent screenshot to', shotNow); + } catch (e) { + log('Failed to save domcontent screenshot:', e && e.message ? e.message : e); + } + try { + const immediateInputs = await page.evaluate(() => document.querySelectorAll('input').length); + log('Immediate input count at domcontentloaded =', immediateInputs); + } catch (e) { + log('Could not evaluate immediate input count:', e && e.message ? e.message : e); + } + + // Install a MutationObserver inside the page to record the first time any + // input element appears. We store the epoch ms in window.__inputsFirstSeen + // and also emit a console log so the test logs capture the exact instant. + try { + await page.evaluate(() => { + try { + window.__inputsFirstSeen = null; + const check = () => { + try { + const count = document.querySelectorAll('input').length; + if (count && window.__inputsFirstSeen === null) { + window.__inputsFirstSeen = Date.now(); + // eslint-disable-next-line no-console + console.log('INPUTS_APPEARED', window.__inputsFirstSeen, 'count=', count); + if (observer) observer.disconnect(); + } + } catch (e) { + // swallow + } + }; + const observer = new MutationObserver(check); + observer.observe(document.body || document.documentElement, { + childList: true, + subtree: true, + attributes: true, + }); + // Run an initial check in case inputs are already present + check(); + } catch (e) { + // ignore page-side errors + } + }); + log('MutationObserver probe installed to detect first input appearance'); + } catch (e) { + log('Could not install MutationObserver probe:', e && e.message ? e.message : e); + } + } catch (e) { + console.error("Failed to load page:", e && e.message ? e.message : e); + // Print a short sniff of the response HTML if available + try { + const content = await page.content(); + console.log("Page content snippet:\n", content.slice(0, 1000)); + } catch (err) { + console.warn( + "Could not read page content:", + err && err.message ? err.message : err + ); + } + throw e; + } + + // Fast-path: wait for a visible input quickly. If that fails, fall back to polling. + let inputsFound = 0; + try { + log('Fast-wait for visible input (5s)'); + await page.waitForSelector('input', { visible: true, timeout: 5000 }); + inputsFound = await page.evaluate(() => document.querySelectorAll('input').length); + log('Fast-wait success, inputsFound=', inputsFound); + } catch (e) { + log('Fast-wait failed (no visible input within 5s), falling back to polling'); + // poll for inputs so we know exactly when they appear rather than sleeping blindly + const pollStart = Date.now(); + for (let i = 0; i < 80; i++) { // 80 * 250ms = 20s fallback + try { + inputsFound = await page.evaluate(() => document.querySelectorAll('input').length); + } catch (err) { + log('evaluate error while polling inputs:', err && err.message ? err.message : err); + } + // Abort the polling if the global timeout has already fired or is about to. + if (_timedOut) { + log('Aborting input polling because global timeout flag is set'); + break; + } + if (Date.now() - t0 > MAX_TEST_MS - 2000) { + log('Approaching global timeout while polling inputs — aborting polling loop'); + break; + } + if (inputsFound && inputsFound > 0) { + log('Inputs appeared after', (Date.now() - pollStart) + 'ms; count=', inputsFound); + break; + } + if (i % 20 === 0) log('still polling for inputs...', i, 'iterations, elapsed', (Date.now() - pollStart) + 'ms'); + await sleep(250); + } + if (!inputsFound) log('No inputs found after fallback polling (~20s)'); + } + + // If the app shows an "Enter your name" prompt, robustly try to fill it + try { + log('Attempting to detect name input by placeholder/aria/label/id or first visible input'); + const candidates = [ + "input[placeholder*='Enter your name']", + "input[placeholder*='enter your name']", + "input[aria-label*='name']", + "input[name='name']", + "input[id*='name']", + ".nameInput input", + // label-based XPath (will be handled specially below) + "xpath://label[contains(normalize-space(.), 'Enter your name')]/following::input[1]", + "xpath://*[contains(normalize-space(.), 'Enter your name')]/following::input[1]", + "input" + ]; + let filled = false; + for (const sel of candidates) { + try { + let el = null; + if (sel.startsWith('xpath:')) { + const path = sel.substring(6); + const nodes = await page.$x(path); + if (nodes && nodes.length) el = nodes[0]; + } else { + el = await page.$(sel); + } + if (el) { + await el.focus(); + const tTypeStart = Date.now(); + await page.keyboard.type('Automaton', { delay: 50 }); + log('Typed name via selector', sel, '(took', Date.now() - tTypeStart + 'ms)'); + // Press Enter to submit if the UI responds to it + await page.keyboard.press('Enter'); + filled = true; + await sleep(500); + break; + } + } catch (inner) { + // ignore selector-specific failures + } + } + + if (!filled) { + // fallback: find the first visible input and type there + const inputs = await page.$$('input'); + for (const input of inputs) { + try { + const box = await input.boundingBox(); + if (box) { + await input.focus(); + const tTypeStart = Date.now(); + await page.keyboard.type('Automaton', { delay: 50 }); + await page.keyboard.press('Enter'); + log('Typed name into first visible input (took', Date.now() - tTypeStart + 'ms)'); + filled = true; + await sleep(500); + break; + } + } catch (inner) {} + } + } + + // Try clicking a button to confirm/join. Match common labels case-insensitively. + const clickTexts = ['set','join','ok','enter','start','confirm']; + let clicked = false; + for (const txt of clickTexts) { + try { + const xpath = `//button[contains(translate(normalize-space(.),'ABCDEFGHIJKLMNOPQRSTUVWXYZ','abcdefghijklmnopqrstuvwxyz'),'${txt}')]`; + const btns = await page.$x(xpath); + if (btns && btns.length) { + await btns[0].click(); + log('Clicked button matching text', txt); + clicked = true; + await sleep(500); + break; + } + } catch (inner) {} + } + if (!clicked) { + // fallback: click submit-type inputs/buttons + const submit = await page.$("input[type=submit], button[type=submit]"); + if (submit) { + await submit.click(); + log('Clicked submit control'); + clicked = true; + await sleep(500); + } + } + + if (!filled && !clicked) log('No name input or submit button found to set name'); + } catch (e) { + log('Could not auto-enter name:', e && e.message ? e.message : e); + } + + // Read the MutationObserver probe timestamp (if it recorded when inputs first appeared) + try { + const firstSeen = await page.evaluate(() => window.__inputsFirstSeen || null); + if (firstSeen) { + const delta = Date.now() - firstSeen; + log('Probe: inputs first seen at', new Date(firstSeen).toISOString(), `(ago ${delta}ms)`); + // Save a screenshot named with the first-seen timestamp to make it easy to correlate + const shotPath = `/workspace/tmp-house-rules-${firstSeen}.png`; + try { + await page.screenshot({ path: shotPath, fullPage: true }); + log('Saved input-appearance screenshot to', shotPath); + } catch (e) { + log('Failed to save input-appearance screenshot:', e && e.message ? e.message : e); + } + // Also save the full HTML at the time inputs first appeared so we can + // inspect the DOM (some UI frameworks render inputs late). + try { + const html = await page.content(); + const outPath = `/workspace/tmp-domcontent-after-inputs-${firstSeen}.html`; + try { + fs.writeFileSync(outPath, html); + log('Saved DOM HTML at input-appearance to', outPath, '(length', html.length + ')'); + } catch (e) { + log('Failed to write post-input DOM HTML:', e && e.message ? e.message : e); + } + // Also capture any intercepted WebSocket sends recorded by the + // in-page interceptor and dump them to a JSON file for later + // verification. + try { + const sends = await page.evaluate(() => window.__wsSends || []); + const wsOut = `/workspace/tmp-ws-sends-${firstSeen}.json`; + try { + fs.writeFileSync(wsOut, JSON.stringify(sends, null, 2)); + log('Saved intercepted WS sends to', wsOut, '(count', (sends && sends.length) + ')'); + // QUICK ASSERTION: ensure a player-name send with Automaton was captured + try { + const parsed = (sends || []).map(s => { + try { return JSON.parse(s.data); } catch (e) { return null; } + }).filter(Boolean); + const hasPlayerName = parsed.some(p => p.type === 'player-name' && ((p.data && p.data.name) === 'Automaton' || (p.name === 'Automaton'))); + if (!hasPlayerName) { + log('ASSERTION FAILED: No player-name send with name=Automaton found in intercepted WS sends'); + // Write a failure marker file for CI to pick up + try { fs.writeFileSync('/workspace/tmp-assert-failed-player-name.txt', 'Missing player-name Automaton'); } catch (e) {} + process.exit(3); + } else { + log('Assertion passed: player-name Automaton was sent by client'); + } + } catch (e) { + log('Error while asserting WS sends:', e && e.message ? e.message : e); + } + } catch (e) { + log('Failed to write intercepted WS sends file:', e && e.message ? e.message : e); + } + } catch (e) { + log('Could not read intercepted WS sends from page:', e && e.message ? e.message : e); + } + } catch (e) { + log('Could not read page content at input-appearance:', e && e.message ? e.message : e); + } + } else { + log('Probe did not record input first-seen timestamp (window.__inputsFirstSeen is null)'); + } + } catch (e) { + log('Could not read window.__inputsFirstSeen:', e && e.message ? e.message : e); + } + + // Ensure we still capture intercepted WS sends even if the probe didn't + // record the input-appearance timestamp. Dump a latest copy and run the + // same assertion so CI will fail fast when player-name is missing. + try { + const sends = await page.evaluate(() => window.__wsSends || []); + const outLatest = '/workspace/tmp-ws-sends-latest.json'; + try { + fs.writeFileSync(outLatest, JSON.stringify(sends, null, 2)); + log('Saved intercepted WS sends (latest) to', outLatest, '(count', (sends && sends.length) + ')'); + } catch (e) { + log('Failed to write latest intercepted WS sends file:', e && e.message ? e.message : e); + } + // Run the same assertion against the latest sends if a per-timestamp + // file was not written earlier. + try { + const parsed = (sends || []).map(s => { + try { return JSON.parse(s.data); } catch (e) { return null; } + }).filter(Boolean); + const hasPlayerName = parsed.some(p => p.type === 'player-name' && ((p.data && p.data.name) === 'Automaton' || (p.name === 'Automaton'))); + if (!hasPlayerName) { + log('ASSERTION FAILED: No player-name send with name=Automaton found in intercepted WS sends (latest)'); + try { fs.writeFileSync('/workspace/tmp-assert-failed-player-name.txt', 'Missing player-name Automaton'); } catch (e) {} + process.exit(3); + } else { + log('Assertion passed (latest): player-name Automaton was sent by client'); + } + } catch (e) { + log('Error while asserting WS sends (latest):', e && e.message ? e.message : e); + } + } catch (e) { + log('Could not read intercepted WS sends for latest dump:', e && e.message ? e.message : e); + } + + // If the global timeout fired while we were running, abort now. + if (_timedOut) { + log('Test aborted due to global timeout flag set after probe check'); + if (browser) try { await browser.close(); } catch (e) {} + process.exit(124); + } + + // Debug: list buttons with their text + const tButtonScan = Date.now(); + const buttons = await page + .$$eval("button", (els) => + els.map((b) => ({ text: b.innerText, id: b.id || null })) + ) + .catch(() => []); + log( + "Found buttons (first 20) (scan took", + Date.now() - tButtonScan + "ms):", + JSON.stringify(buttons.slice(0, 20), null, 2) + ); + + // Try to open House Rules by clicking the relevant button if present + const btn = await page.$x("//button[contains(., 'House Rules')]"); + if (btn && btn.length) { + log("Found House Rules button, clicking"); + await btn[0].click(); + await sleep(500); + } else { + log( + "House Rules button not found by text; attempting fallback selectors" + ); + // fallback: try a few likely selectors + const fallbacks = [ + ".Actions button", + "button[aria-label='House Rules']", + "button[data-testid='house-rules']", + ]; + let clicked = false; + for (const sel of fallbacks) { + const tSelStart = Date.now(); + const el = await page.$(sel); + log( + "Checked selector", + sel, + " (took", + Date.now() - tSelStart + "ms) ->", + !!el + ); + if (el) { + log("Clicking fallback selector", sel); + await el.click(); + clicked = true; + await sleep(500); + break; + } + } + if (!clicked) console.log("No fallback selector matched"); + } + + // Wait for the HouseRules dialog to appear + try { + const tWaitStart = Date.now(); + await page.waitForSelector(".HouseRules", { timeout: 2000 }); + log( + "HouseRules dialog is present (waited", + Date.now() - tWaitStart + "ms)" + ); + } catch (e) { + log("HouseRules dialog did not appear"); + // Dump a small HTML snippet around where it might be + try { + const snippet = await page.$$eval("body *:nth-child(-n+60)", (els) => + els.map((e) => e.outerHTML).join("\n") + ); + console.log( + "Body snippet (first ~60 elements):\n", + snippet.slice(0, 4000) + ); + } catch (err) { + log( + "Could not capture snippet:", + err && err.message ? err.message : err + ); + } + } + + // Evaluate whether switches are disabled and capture extra debug info + const switches = await page + .$$eval(".HouseRules .RuleSwitch", (els) => + els.map((e) => ({ + id: e.id || "", + disabled: e.disabled, + outer: e.outerHTML, + })) + ) + .catch(() => []); + log("Switches found:", switches.length); + switches.forEach((s, i) => { + log(`${i}: id='${s.id}', disabled=${s.disabled}`); + if (s.outer && s.outer.length > 0) { + log(` outerHTML (first 200 chars): ${s.outer.slice(0, 200)}`); + } + }); + + // Also attempt to log the current game state and name visible in DOM if present + try { + const stateText = await page.$eval(".Table, body", (el) => + document.body.innerText.slice(0, 2000) + ); + log( + "Page text snippet:\n", + stateText.split("\n").slice(0, 40).join("\n") + ); + } catch (err) { + log( + "Could not extract page text snippet:", + err && err.message ? err.message : err + ); + } + + // Save a screenshot for inspection (workspace is mounted when running container) + const out = "/workspace/tmp-house-rules.png"; + try { + const tShot = Date.now(); + await page.screenshot({ path: out, fullPage: true }); + log("Screenshot saved to", out, "(took", Date.now() - tShot + "ms)"); + } catch (e) { + log("Screenshot failed:", e && e.message ? e.message : e); + } + + await browser.close(); + clearGlobalTimeout(); + log("Puppeteer test finished successfully"); + } catch (err) { + log("Puppeteer test failed:", err && err.stack ? err.stack : err); + if (browser) + try { + await browser.close(); + } catch (e) {} + process.exit(2); + } +})(); diff --git a/tools/puppeteer-test/tmp_puppeteer.js b/tools/puppeteer-test/tmp_puppeteer.js new file mode 100644 index 0000000..656b115 --- /dev/null +++ b/tools/puppeteer-test/tmp_puppeteer.js @@ -0,0 +1,32 @@ +const puppeteer = require('puppeteer'); +(async () => { + console.log('launching'); + const browser = await puppeteer.launch({ args: ['--no-sandbox','--disable-setuid-sandbox'], ignoreHTTPSErrors: true }); + const page = await browser.newPage(); + const url = 'https://localhost:3001/ketr.ketran/'; + console.log('goto', url); + try { + await page.goto(url, { waitUntil: 'networkidle2', timeout: 30000 }); + console.log('loaded'); + } catch (e) { + console.error('load failed', e.message); + await browser.close(); + process.exit(2); + } + await page.waitForTimeout(3000); + const btn = await page.$x("//button[contains(., 'House Rules')]"); + if (btn && btn.length) { + console.log('Found House Rules button, clicking'); + await btn[0].click(); + await page.waitForTimeout(500); + } else { + console.log('House Rules button not found by text; trying .Actions button'); + const btn2 = await page.$('.Actions button'); + if (btn2) { await btn2.click(); await page.waitForTimeout(500); } + } + try { await page.waitForSelector('.HouseRules', { timeout: 5000 }); console.log('HouseRules appeared'); } catch(e) { console.error('HouseRules did not appear'); } + const switches = await page.$$eval('.HouseRules .RuleSwitch', els => els.map(e => ({ id: e.id || '', disabled: e.disabled }))); + console.log('switches', JSON.stringify(switches, null, 2)); + try { await page.screenshot({ path: '/tmp/house-rules.png', fullPage: true }); console.log('screenshot saved to /tmp/house-rules.png'); } catch(e) { console.warn('screenshot failed', e.message); } + await browser.close(); +})();