2f0edf51cf
feedPalace() raced mempalace_mine against a bare setTimeout(reject, feedMineTimeoutMs) and never cleared it. When the mine won (the normal case) the losing 300 000 ms timer stayed referenced. Interactive and RPC mode call process.exit() and never showed it. Print mode (`pi -p`, `--mode json`) returns and waits for an empty event loop, so every `pi -p` on a devbox printed its answer and then idled for the rest of the five minutes. Measured on tor-ms22 (pi 1.1.0, NODE_OPTIONS=--import probe): - before: PONG at 4 s, exit at 315.1 s. The 300 000 ms timer from mempalace.ts:1144 (created +15.1 s) was the ONLY active resource from +50 s on. - after: PONG at 3 s, exit at 45.2 s, the moment the mine's socket closed. - MEMPALACE_FEED=0: 3.8 s. pi 1.0.0 behaved the same as 1.1.0, so this is not a pi regression. The timer is now cleared in a finally once the race settles. It stays referenced while it runs because it is the liveness guard. scripts/test-feed-exit.sh loads the type-stripped SHIPPED extension under a stub pi with a fake palace in a separate process and fires session_shutdown: - A: the mine answers in 1 s with a 20 s deadline. Node must exit within 3 s of the handler resolving. The pre-fix source FAILS here (19 000 ms). - B: the mine never answers, 2 s deadline. The deadline still ends the wait, and the failure is logged. All five scripts/test-*.sh pass. README Debugging section: the remaining expected wait (one catch-up feed per session, ~45 s here) and MEMPALACE_FEED=0 for scripts that want an instant return.
151 lines
8.2 KiB
Bash
Executable File
151 lines
8.2 KiB
Bash
Executable File
#!/usr/bin/env bash
|
|
# test-feed-exit.sh — once the feed's mine has settled, the pi extension in
|
|
# extensions/pi/mempalace.ts must leave NOTHING behind that keeps node alive.
|
|
#
|
|
# WHY THIS EXISTS. `pi -p` (print mode, also `--mode json`) does not call
|
|
# process.exit(): it returns from main() and lets node exit when the event loop
|
|
# is empty. Interactive and RPC mode call process.exit() and never noticed. The
|
|
# feed raced its mine against a bare
|
|
# new Promise((_, reject) => setTimeout(reject, feedMineTimeoutMs))
|
|
# whose timer was never cleared. When the mine won the race (the normal case,
|
|
# 30-60 s), the losing 300 000 ms timer stayed referenced, so every `pi -p` on a
|
|
# devbox printed its answer and then sat idle for the rest of those 5 minutes.
|
|
# Measured on tor-ms22 2026-10-13: the 300 000 ms timer from mempalace.ts was the
|
|
# ONLY active resource from 35 s after the mine returned until exit at ~316 s.
|
|
#
|
|
# Like test-mcp-call-timeout.sh, it runs the SHIPPED text: the whole extension
|
|
# is type-stripped with node's own stripper (the `typebox` import is replaced by
|
|
# a stub) and loaded under a stub pi. A fake feed helper prints MINE_SOURCE, and
|
|
# a local JSON-RPC server (in a SEPARATE process, so it cannot hold the driver's
|
|
# event loop) answers the mine. The driver fires session_shutdown, which awaits
|
|
# the feed, and then simply returns. The harness measures how long node takes to
|
|
# exit after that.
|
|
# A. mine answers in 1 s, deadline 20 s: node must exit right after the
|
|
# handler resolves. Before the fix it lived until the 20 s deadline.
|
|
# B. mine never answers, deadline 2 s: the deadline is still a liveness
|
|
# guard; the handler resolves at about 2 s and node exits.
|
|
set -euo pipefail
|
|
REPO_ROOT="$(cd "$(dirname "${BASH_SOURCE[0]}")/.." && pwd)"
|
|
SRC="${1:-$REPO_ROOT/extensions/pi/mempalace.ts}"
|
|
WORK="$(mktemp -d)"
|
|
SERVER_PID=""
|
|
cleanup() { [ -n "$SERVER_PID" ] && kill "$SERVER_PID" 2>/dev/null; rm -rf "$WORK"; }
|
|
trap cleanup EXIT
|
|
[ -r "$SRC" ] || { echo "FAIL: cannot read $SRC" >&2; exit 2; }
|
|
|
|
# ---------------------------------------------------------------- extractor ---
|
|
cat >"$WORK/extract.mjs" <<'EXTRACT'
|
|
import { readFileSync, writeFileSync } from "node:fs";
|
|
import { stripTypeScriptTypes } from "node:module";
|
|
let src = readFileSync(process.argv[2], "utf8");
|
|
const imp = 'import { Type } from "typebox";';
|
|
if (!src.includes(imp)) throw new Error(`expected import line not found: ${imp}`);
|
|
src = src.replace(imp, 'const Type = { Unsafe: (s) => s, Object: () => ({}) };');
|
|
if (!src.includes("feedPalace")) throw new Error("extension does not mention feedPalace");
|
|
writeFileSync(process.argv[3], stripTypeScriptTypes(src, { mode: "strip" }));
|
|
EXTRACT
|
|
node --no-warnings "$WORK/extract.mjs" "$SRC" "$WORK/ext.mjs" || exit 2
|
|
node --check "$WORK/ext.mjs" || { echo "FAIL: stripped extension does not parse" >&2; exit 2; }
|
|
echo "[extract] type-stripped $(basename "$SRC") ($(wc -c <"$WORK/ext.mjs") bytes)"
|
|
|
|
# ------------------------------------------------------------ fake feed bin ---
|
|
cat >"$WORK/fake-feed" <<'FEED'
|
|
#!/bin/sh
|
|
echo "MINE_SOURCE=/nonexistent/fake-stage"
|
|
FEED
|
|
chmod +x "$WORK/fake-feed"
|
|
|
|
# ----------------------------------------------------------- fake palace ------
|
|
# Sessionless JSON-RPC like `mempalace-mcp --transport http`. The mine's delay
|
|
# is set per case through a tiny control endpoint (GET /delay/<ms>), so one
|
|
# server serves both cases.
|
|
cat >"$WORK/server.mjs" <<'SERVER'
|
|
import { createServer } from "node:http";
|
|
import { appendFileSync } from "node:fs";
|
|
let mineDelay = 1000;
|
|
const server = createServer((req, res) => {
|
|
if (req.url.startsWith("/delay/")) { mineDelay = Number(req.url.slice(7)); res.end("ok"); return; }
|
|
let body = "";
|
|
req.on("data", (c) => (body += c));
|
|
req.on("end", () => {
|
|
const msg = JSON.parse(body);
|
|
if (msg.id === undefined) { res.writeHead(202); res.end(); return; }
|
|
const reply = (result) => {
|
|
if (res.destroyed) return;
|
|
res.writeHead(200, { "content-type": "application/json", connection: "close" });
|
|
res.end(JSON.stringify({ jsonrpc: "2.0", id: msg.id, result }));
|
|
};
|
|
if (msg.method === "initialize") return reply({ protocolVersion: "2024-11-05", capabilities: {}, serverInfo: { name: "fake", version: "0" } });
|
|
if (msg.method === "tools/list") return reply({ tools: [{ name: "mempalace_mine", description: "", inputSchema: { type: "object" } }] });
|
|
if (msg.method === "tools/call") {
|
|
appendFileSync(process.env.CALL_LOG, `${msg.params?.name} source=${msg.params?.arguments?.source}\n`);
|
|
return void setTimeout(() => reply({ content: [{ type: "text", text: "mined" }] }), mineDelay);
|
|
}
|
|
reply({});
|
|
});
|
|
});
|
|
server.listen(0, "127.0.0.1", () => console.log(server.address().port));
|
|
SERVER
|
|
CALL_LOG="$WORK/calls.log" node "$WORK/server.mjs" >"$WORK/port" &
|
|
SERVER_PID=$!
|
|
for _ in $(seq 50); do [ -s "$WORK/port" ] && break; sleep 0.1; done
|
|
PORT="$(cat "$WORK/port")"
|
|
[ -n "$PORT" ] || { echo "FAIL: fake palace did not start" >&2; exit 2; }
|
|
|
|
# ------------------------------------------------------------------ driver ----
|
|
# Loads the extension under a stub pi, fires session_shutdown, prints when the
|
|
# handler resolved, then RETURNS. Anything still referenced keeps node alive.
|
|
cat >"$WORK/driver.mjs" <<'DRIVER'
|
|
const t0 = Date.now();
|
|
const handlers = {};
|
|
const pi = new Proxy({}, {
|
|
get: (_t, k) => k === "on" ? (ev, fn) => { (handlers[ev] ||= []).push(fn); } : () => {},
|
|
});
|
|
const { default: ext } = await import("./ext.mjs");
|
|
await ext(pi);
|
|
if (!handlers.session_shutdown) { console.log("NO_SHUTDOWN_HANDLER"); process.exitCode = 3; }
|
|
else {
|
|
for (const fn of handlers.session_shutdown) await fn({ type: "session_shutdown", reason: "quit" }, {});
|
|
console.log(`HANDLER_RESOLVED_MS=${Date.now() - t0}`);
|
|
}
|
|
process.on("exit", () => console.log(`EXIT_MS=${Date.now() - t0}`));
|
|
DRIVER
|
|
|
|
failures=0
|
|
check() { if [ "$1" = 0 ]; then echo "ok $2"; else echo "FAIL $2"; failures=$((failures + 1)); fi; }
|
|
|
|
run_case() { # $1 mine delay ms, $2 feed mine timeout ms -> sets HANDLER EXIT RC
|
|
curl -fsS "http://127.0.0.1:$PORT/delay/$1" >/dev/null
|
|
: >"$WORK/calls.log"
|
|
set +e
|
|
out="$(cd "$WORK" && env -u MEMPALACE_REMOTE_TOKEN -u MEMPALACE_PI_DEVICE \
|
|
MEMPALACE_REMOTE_URL="http://127.0.0.1:$PORT/mcp" MEMPALACE_FEED=1 \
|
|
MEMPALACE_FEED_BIN="$WORK/fake-feed" MEMPALACE_FEED_MINE_TIMEOUT_MS="$2" \
|
|
timeout 60 node --no-warnings driver.mjs 2>"$WORK/driver.err")"
|
|
RC=$?
|
|
set -e
|
|
HANDLER="$(printf '%s\n' "$out" | sed -n 's/^HANDLER_RESOLVED_MS=//p')"
|
|
EXIT="$(printf '%s\n' "$out" | sed -n 's/^EXIT_MS=//p')"
|
|
MINES="$(grep -c '^mempalace_mine source=/nonexistent/fake-stage' "$WORK/calls.log" || true)"
|
|
}
|
|
|
|
# A. normal case: the mine wins the race.
|
|
run_case 1000 20000
|
|
echo "[A] rc=$RC handler=${HANDLER:-?}ms exit=${EXIT:-?}ms mines=$MINES"
|
|
check "$([ "$RC" = 0 ] && echo 0 || echo 1)" "A: driver exits cleanly (rc=$RC)"
|
|
check "$([ "$MINES" = 1 ] && echo 0 || echo 1)" "A: shutdown really mined the staged source once (not a vacuous pass)"
|
|
check "$([ -n "$HANDLER" ] && [ "$HANDLER" -ge 900 ] && [ "$HANDLER" -lt 10000 ] && echo 0 || echo 1)" "A: session_shutdown awaited the 1 s mine (${HANDLER:-?} ms)"
|
|
check "$([ -n "$EXIT" ] && [ -n "$HANDLER" ] && [ $((EXIT - HANDLER)) -lt 3000 ] && echo 0 || echo 1)" \
|
|
"A: node exits within 3 s of the handler resolving ($(( ${EXIT:-0} - ${HANDLER:-0} )) ms; the 20 s mine deadline must not hold it)"
|
|
|
|
# B. wedged palace: the deadline must still end the wait.
|
|
run_case 60000 2000
|
|
echo "[B] rc=$RC handler=${HANDLER:-?}ms exit=${EXIT:-?}ms mines=$MINES"
|
|
check "$([ "$RC" = 0 ] && echo 0 || echo 1)" "B: driver exits cleanly (rc=$RC)"
|
|
check "$([ -n "$HANDLER" ] && [ "$HANDLER" -ge 1900 ] && [ "$HANDLER" -lt 10000 ] && echo 0 || echo 1)" "B: session_shutdown gives up at the 2 s deadline (${HANDLER:-?} ms)"
|
|
check "$(grep -q 'feed (shutdown) failed: .*2000ms' "$WORK/driver.err" && echo 0 || echo 1)" "B: the timeout is reported on stderr"
|
|
check "$([ -n "$EXIT" ] && [ -n "$HANDLER" ] && [ $((EXIT - HANDLER)) -lt 3000 ] && echo 0 || echo 1)" \
|
|
"B: node exits within 3 s of the handler resolving ($(( ${EXIT:-0} - ${HANDLER:-0} )) ms; the 60 s server delay must not hold it)"
|
|
|
|
if [ "$failures" = 0 ]; then echo "PASS: all assertions held"; else echo "FAIL: $failures assertion(s) failed"; exit 1; fi
|