8000 fix(ci): recover baseline SQLite WAL startup race by adeelahmad · Pull Request #728 · adeelahmad/lense · GitHub
[go: up one dir, main page]

Skip to content
8000
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 2 additions & 0 deletions .github/workflows/upgrade.yml
Original file line number Diff line number Diff line change
Expand Up @@ -53,6 +53,8 @@ jobs:
with:
cache-local-path: ${{ runner.environment == 'self-hosted' && format('{0}/uv-cache', runner.tool_cache) || '' }}
python-version: "3.12"
- name: Test upgrade startup supervision
run: python3 ci/upgrade/test_startup.py -v
- name: Upgrade and check
env:
FROM: ${{ inputs.from }}
Expand Down
1 change: 1 addition & 0 deletions changelog.d/upgrade-baseline-startup.fixed.md
Original file line number Diff line number Diff line change
@@ -0,0 +1 @@
The upgrade check restarts an old-release worker at most twice after its known SQLite WAL initialization lock race, preserving failed attempt logs. Both versions still start API and worker concurrently; target-version failures and all upgrade data, backup and migration checks remain strict.
148 changes: 148 additions & 0 deletions ci/upgrade/test_startup.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,148 @@
"""Exercise the real startup shell function without Docker or backend dependencies."""

import os
from pathlib import Path
import shlex
import subprocess
import sys
import tempfile
import unittest

SCRIPT = Path(__file__).with_name("upgrade.sh").read_text()
STARTUP = SCRIPT[SCRIPT.index("lens_start() {") : SCRIPT.index("lens_stop() {")]
WAL_ERROR = (
'File "app/domain/textindex.py", line 203, in __init__\n'
' self.con.execute("PRAGMA journal_mode=WAL")\n'
"sqlite3.OperationalError: database is locked\n"
)


class StartupTests(unittest.TestCase):
def run_startup(self, label="from", failures=1, error=WAL_ERROR, api_fails=False):
with tempfile.TemporaryDirectory() as directory:
root = Path(directory)
(root / "fastapi_backend").mkdir()
(root / "bin").mkdir()
(root / "out").mkdir()
programs = {
"fastapi": """
import os, time
from pathlib import Path
root = Path(os.environ['TEST_ROOT'])
(root / 'api-started').touch()
if os.environ['API_FAILS'] == '1':
raise SystemExit(1)
# Both processes must have started before the API can become ready.
while not (root / 'worker-started').exists():
time.sleep(.005)
(root / 'api-ready').touch()
while True:
time.sleep(1)
""",
"lens": """
import os, time
from pathlib import Path
root = Path(os.environ['TEST_ROOT'])
count_file = root / 'attempts'
count = int(count_file.read_text()) + 1 if count_file.exists() else 1
count_file.write_text(str(count))
(root / 'worker-started').touch()
if count <= int(os.environ['FAILURES']):
print(os.environ['WORKER_ERROR'], end='', flush=True)
raise SystemExit(1)
print('Ctrl-C to stop', flush=True)
while True:
time.sleep(1)
""",
"curl": """
import os, time
from pathlib import Path
time.sleep(.03)
raise SystemExit(0 if (Path(os.environ['TEST_ROOT']) / 'api-ready').exists() else 1)
""",
}
for name, program in programs.items():
binary = root / "bin" / name
binary.write_text(f"#!{sys.executable}\n{program}")
binary.chmod(0o755)
script = (
"set -euo pipefail\n"
'OUT="$TEST_ROOT/out"; API_PORT=1; PIDS=()\n'
'cleanup() { for p in "${PIDS[@]}"; do kill "$p" 2>/dev/null || true; '
"done; wait || true; }\n"
"trap cleanup EXIT\n"
"sleep() { /bin/sleep .02; }\n"
+ STARTUP
+ f'lens_start {shlex.quote(label)} "$TEST_ROOT" "$TEST_ROOT"\n'
)
result = subprocess.run(
["bash", "-c", script],
env={
**os.environ,
"PATH": f"{root / 'bin'}:{os.environ['PATH']}",
"TEST_ROOT": str(root),
"FAILURES": str(failures),
"WORKER_ERROR": error,
"API_FAILS": str(int(api_fails)),
},
text=True,
capture_output=True,
timeout=15,
)
attempts = root / "attempts"
logs = {p.name: p.read_text() for p in (root / "out").iterdir()}
return result, int(attempts.read_text()) if attempts.exists() else 0, logs

def test_concurrent_start_without_retry(self):
result, attempts, logs = self.run_startup(failures=0)
self.assertEqual(result.returncode, 0, result.stdout + result.stderr)
self.assertEqual(attempts, 1)
self.assertEqual(set(logs), {"from-api.log", "from-worker.log"})

def test_baseline_wal_race_restarts_worker_and_preserves_log(self):
result, attempts, logs = self.run_startup()
self.assertEqual(result.returncode, 0, result.stdout + result.stderr)
self.assertEqual(attempts, 2)
self.assertEqual(logs["from-worker-attempt-1.log"], WAL_ERROR)
self.assertEqual(logs["from-worker.log"], "Ctrl-C to stop\n")

def test_persistent_baseline_wal_failure_is_bounded(self):
result, attempts, logs = self.run_startup(failures=99)
self.assertNotEqual(result.returncode, 0)
self.assertEqual(attempts, 3)
self.assertEqual(logs["from-worker-attempt-2.log"], WAL_ERROR)
self.assertEqual(logs["from-worker.log"], WAL_ERROR)

def test_target_wal_failure_is_not_retried(self):
result, attempts, logs = self.run_startup(label="to")
self.assertNotEqual(result.returncode, 0)
self.assertEqual(attempts, 1)
self.assertEqual(set(logs), {"to-api.log", "to-worker.log"})

def test_unrelated_worker_failures_are_not_retried(self):
for error in (
"RuntimeError: failed migration\n",
"sqlite3.OperationalError: database is locked\n",
WAL_ERROR.replace("database is locked", "database disk image is malformed"),
WAL_ERROR.replace("PRAGMA journal_mode=WAL", "CREATE TABLE example"),
):
with self.subTest(error=error):
result, attempts, _ = self.run_startup(error=error)
self.assertNotEqual(result.returncode, 0)
self.assertEqual(attempts, 1)
10BC8
def test_dead_worker_with_stale_ready_message_fails(self):
result, attempts, _ = self.run_startup(
error="Ctrl-C to stop\nRuntimeError: fatal\n"
)
self.assertNotEqual(result.returncode, 0)
self.assertEqual(attempts, 1)

def test_api_failure_is_not_retried(self):
result, attempts, _ = self.run_startup(api_fails=True)
self.assertNotEqual(result.returncode, 0)
self.assertLessEqual(attempts, 1)


if __name__ == "__main__":
unittest.main()
27 changes: 24 additions & 3 deletions ci/upgrade/upgrade.sh
Original file line number Diff line number Diff line change
Expand Up @@ -62,18 +62,39 @@ sync_backend() { # TREE VENV: the backend's packages, as its image installs them
}

lens_start() { # LABEL TREE VENV: the API and a worker at once, as the production stack starts them
local label=$1 tree=$2 venv=$3
local label=$1 tree=$2 venv=$3 worker_restarts=0
(cd "$tree/fastapi_backend" && exec "$venv/bin/fastapi" run app/main.py --host 127.0.0.1 --port "$API_PORT") \
>"$OUT/$label-api.log" 2>&1 &
API_PID=$!
(cd "$tree/fastapi_backend" && exec "$venv/bin/lens" worker) >"$OUT/$label-worker.log" 2>&1 &
WORKER_PID=$!
PIDS+=("$API_PID" "$WORKER_PID")
for _ in $(seq 180); do
if curl -sf -o /dev/null "http://127.0.0.1:$API_PORT/api/v1/auth/status" && grep -q 'Ctrl-C to stop' "$OUT/$label-worker.log"; then
if ! kill -0 "$API_PID" 2>/dev/null; then break; fi
if ! kill -0 "$WORKER_PID" 2>/dev/null; then
# Old releases cannot be patched here. Reproduce production's restart policy only for the known
# empty-index WAL race before seeding. Never retry the version under test or other startup failures.
if [ "$label" != from ] || [ "$worker_restarts" -ge 2 ] ||
! grep -Fq 'textindex.py' "$OUT/$label-worker.log" ||
! grep -Fq 'PRAGMA journal_mode=WAL' "$OUT/$label-worker.log" ||
! grep -Fxq 'sqlite3.OperationalError: database is locked' "$OUT/$label-worker.log"; then
break
fi
wait "$WORKER_PID" 2>/dev/null || true
worker_restarts=$((worker_restarts + 1))
mv "$OUT/$label-worker.log" "$OUT/$label-worker-attempt-$worker_restarts.log"
echo "Restarting baseline worker after SQLite WAL startup race ($worker_restarts/2)"
sleep 1
(cd "$tree/fastapi_backend" && exec "$venv/bin/lens" worker) >"$OUT/$label-worker.log" 2>&1 &
WORKER_PID=$!
PIDS+=("$WORKER_PID")
continue
fi
if curl -sf -o /dev/null "http://127.0.0.1:$API_PORT/api/v1/auth/status" &&
grep -q 'Ctrl-C to stop' "$OUT/$label-worker.log" &&
kill -0 "$API_PID" 2>/dev/null && kill -0 "$WORKER_PID" 2>/dev/null; then
return 0
fi
if ! kill -0 "$API_PID" 2>/dev/null || ! kill -0 "$WORKER_PID" 2>/dev/null; then break; fi
sleep 1
done
tail -n 40 "$OUT/$label-api.log" "$OUT/$label-worker.log"
Expand Down
5 changes: 4 additions & 1 deletion docs/database.md
8
Original file line number Diff line number Diff line change
Expand Up @@ -159,7 +159,10 @@ requests that change the backend, and by hand from any version (Actions > Upgrad
older version; `ci/local-ci.sh` runs it too):

1. The last release (the newest `vX.Y.Z` tag) starts as the production stack runs it, the API and a worker on the
SurrealDB server its `docker-compose.prod.yml` names, with an empty database.
SurrealDB server its `docker-compose.prod.yml` names, with an empty database. If the old worker exits with the
known SQLite WAL initialization lock error, it is restarted at most twice, like production's restart policy;
failed attempts are kept in separate logs. Other failures stop the check. The version being upgraded to is
never retried, so its concurrent startup and migration failures remain visible.
2. It's seeded through its API (`ci/upgrade/lens_upgrade.py seed`): two transcripts and their analysis, an entity, a
note and a comment on an asset, a notes page, a conversation, an MCP server with a token, an API key and settings.
What the API shows of them is kept.
Expand Down
Loading
0