Skip to content

Commit 8bb579d

Browse files
yoomlamclaude
andcommitted
fix(lik-ui): keep the scheduled-runs DB connection alive across a long run
The scheduled-runs cron has failed for three days with `PoolTimeout: couldn't get a connection after 5.00 sec` — always at the terminal `complete_run`, and always on a run long enough (33–40 min) to leave the pooled connection idle for that whole stretch. The agent runs themselves completed; only recording the outcome failed, which aborted the scan and left the row to be reclaimed as `abandoned` (and the completed work repeated) on the next tick. The path to the public Postgres endpoint silently drops a long-idle connection without a FIN, so the checkout-time check can block on TCP retransmission far past the 5s budget and then report a timeout with no attempt left to reconnect. - Enable TCP keepalives (plus `connect_timeout`) on the conninfo: the connection now survives the idle stretch, and a dead one is reported in seconds instead of blocking. - Make the pool's checkout timeout configurable; the scanner uses 30s so a stale connection can be replaced, while a web request still fails fast. - Retry a run's terminal write, and if it still cannot be recorded, finish the remaining rows and exit non-zero instead of raising out of the scan. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
1 parent 2bde625 commit 8bb579d

4 files changed

Lines changed: 112 additions & 9 deletions

File tree

lik-ui/scripts/run_scheduled.py

Lines changed: 51 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -37,6 +37,13 @@
3737
# the whole CI job. The job's timeout-minutes must exceed max_runtime_s + this margin.
3838
_HARD_TIMEOUT_MARGIN_S = 120
3939

40+
# How long a DB connection checkout may take in this process (see ``main``).
41+
_DB_CHECKOUT_TIMEOUT_S = 30
42+
43+
# Waits between attempts at a run's terminal DB write (see ``_record``). One entry per attempt; the
44+
# last entry's wait is never used. Short enough to stay well inside the job's timeout.
45+
_RECORD_RETRY_BACKOFF_S = (2, 5, 10, 0)
46+
4047

4148
class _HardRuntimeBackstop:
4249
"""Process-level runtime guard: guarantees a claimed row terminates and is recorded even if the
@@ -69,6 +76,33 @@ def _chat_url(base_url: str, session_id: str) -> str:
6976
return f"{base}/chat/{session_id}" if base else session_id
7077

7178

79+
def _record(write, *args, **kwargs) -> bool:
80+
"""Perform a run's terminal DB write, retrying a transient connection failure. Returns whether
81+
it succeeded.
82+
83+
This write happens after a long stretch of no DB traffic (the whole agent run), so it is the
84+
one most exposed to a dropped connection to the public Postgres endpoint. A single blip here
85+
used to raise out of the scan, aborting every remaining row and leaving this row's outcome
86+
unrecorded (it is then reclaimed as ``abandoned`` on the next scan, and the completed run is
87+
needlessly repeated). Retrying, and at worst continuing, keeps one blip from costing the scan."""
88+
for attempt, backoff_s in enumerate(_RECORD_RETRY_BACKOFF_S, start=1):
89+
try:
90+
write(*args, **kwargs)
91+
return True
92+
except Exception as exc: # noqa: BLE001 - any DB failure here is worth another try
93+
last = attempt == len(_RECORD_RETRY_BACKOFF_S)
94+
print(
95+
f"[scheduled] recording the outcome failed (attempt {attempt}"
96+
f"{'' if last else ', retrying'}): {exc}",
97+
file=sys.stderr,
98+
flush=True,
99+
)
100+
if last:
101+
return False
102+
time.sleep(backoff_s)
103+
return False
104+
105+
72106
def run_due_schedules(store, sessions_client, vault_client, agents, base_url="") -> tuple[int, int]:
73107
"""Claim and run every due schedule. Returns ``(ran, failed)``. One row's failure never
74108
aborts the scan — each is isolated and its outcome recorded on its own row. ``base_url`` is
@@ -91,7 +125,7 @@ def _log_session(session_id, run_id=run_id, agent=row["agent_name"]):
91125
)
92126
except Exception as exc: # noqa: BLE001 - never let one row (incl. a backstop trip) abort the scan
93127
duration_s = round(time.monotonic() - started)
94-
store.complete_run(run_id, "failed", str(exc), None, duration_s=duration_s)
128+
_record(store.complete_run, run_id, "failed", str(exc), None, duration_s=duration_s)
95129
failed += 1
96130
print(f"[scheduled] run {run_id} raised after {duration_s}s, recorded failed: {exc}", file=sys.stderr)
97131
continue
@@ -100,14 +134,23 @@ def _log_session(session_id, run_id=run_id, agent=row["agent_name"]):
100134
if outcome.status == AUTH_LAPSED:
101135
# Pause instead of advancing — re-running every cadence would just re-fail until the
102136
# owner re-authenticates interactively. The Settings badge shows "needs re-auth".
103-
store.pause_and_flag(run_id, "needs_reauth", error=outcome.error, duration_s=duration_s)
137+
recorded = _record(
138+
store.pause_and_flag, run_id, "needs_reauth", error=outcome.error, duration_s=duration_s
139+
)
104140
else:
105-
store.complete_run(run_id, outcome.status, outcome.error, outcome.skipped or None, duration_s=duration_s)
141+
recorded = _record(
142+
store.complete_run, run_id, outcome.status, outcome.error, outcome.skipped or None,
143+
duration_s=duration_s,
144+
)
106145

107146
ran += 1
108-
if outcome.status in _FAILURE_STATUSES:
147+
# An unrecorded outcome is a job-level failure even when the run itself succeeded: the row
148+
# stays in flight and the next scan will re-run work that already completed.
149+
if outcome.status in _FAILURE_STATUSES or not recorded:
109150
failed += 1
110151
note = f" skipped={len(outcome.skipped)}" if outcome.skipped else ""
152+
if not recorded:
153+
note += " (outcome NOT recorded — the row will be reclaimed next scan)"
111154
where = f" {_chat_url(base_url, outcome.session_id)}" if outcome.session_id else ""
112155
# Duration is logged and persisted (last_duration_s) so max_runtime can be tuned per agent
113156
# from real run times instead of guessed.
@@ -128,7 +171,10 @@ def main() -> int:
128171
file=sys.stderr,
129172
)
130173
return 1
131-
store = Store(Database(settings.conninfo))
174+
# A generous checkout timeout (vs. the web app's default): this process leaves its connection
175+
# idle for a whole agent run, so re-establishing one before the terminal write is worth the
176+
# wait — no user is waiting on a page here, and losing the write costs a repeated run.
177+
store = Store(Database(settings.conninfo, checkout_timeout=_DB_CHECKOUT_TIMEOUT_S))
132178
agents_client = build_agents_client(settings)
133179
agents = resolve_agent_options(settings, agents_client)
134180
sessions_client = build_sessions_client(settings)

lik-ui/src/lik_ui/db.py

Lines changed: 11 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -18,20 +18,28 @@ class Database:
1818
"""Owns the Postgres connection pool. The app holds one; call sites borrow
1919
connections through ``connection()`` and never open their own."""
2020

21-
def __init__(self, conninfo: str, *, min_size: int = 1, max_size: int = 4):
21+
def __init__(self, conninfo: str, *, min_size: int = 1, max_size: int = 4, checkout_timeout: float = 5):
2222
# check on checkout: the scheduled-runs scanner borrows a connection for claim_due_runs,
2323
# then holds the pool idle for a whole multi-minute agent run (no DB traffic) before the
2424
# terminal complete_run. The public Postgres/network silently drops that idle connection,
2525
# so an unchecked pool would hand back a dead socket and the final write would fail with
2626
# "SSL error: unexpected eof while reading" — losing the run's recorded outcome.
2727
# check_connection validates (and the pool reconnects) on checkout, so a stale connection
28-
# is replaced before use instead of erroring mid-write.
28+
# is replaced before use instead of erroring mid-write. Keepalives in the conninfo bound
29+
# how long that check can block on a dead socket (see Settings.conninfo).
30+
#
31+
# ``checkout_timeout`` must leave room for the check to fail AND a replacement connection to
32+
# be opened (the pool backs off ~1s between check attempts, and a fresh TLS connection to
33+
# the public endpoint takes a moment): too small a budget turns a merely stale connection
34+
# into a PoolTimeout. The default suits serving a web request (waiting longer than that just
35+
# stalls a page); the scheduled-runs scanner raises it, because there its terminal write is
36+
# worth waiting out — losing it means re-running a whole completed agent run.
2937
self.pool = ConnectionPool(
3038
conninfo,
3139
min_size=min_size,
3240
max_size=max_size,
3341
open=True,
34-
timeout=5,
42+
timeout=checkout_timeout,
3543
check=ConnectionPool.check_connection,
3644
)
3745

lik-ui/src/lik_ui/settings.py

Lines changed: 8 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -269,9 +269,16 @@ def agent_roster(self) -> list[AgentRosterEntry]:
269269

270270
@property
271271
def conninfo(self) -> str:
272+
# TCP keepalives are not optional here: the scheduled-runs scanner leaves its pooled
273+
# connection idle for a whole multi-minute agent run before the terminal write, and the
274+
# path to the public Postgres endpoint silently drops a long-idle connection (no FIN). With
275+
# keepalives the connection stays alive across that idle, and if it does die the kernel
276+
# reports it in ~keepalives_idle + count*interval instead of letting the next query block
277+
# on TCP retransmission for minutes. connect_timeout bounds re-connecting the same way.
272278
return (
273279
f"host={self.db_host} port={self.db_port} dbname={self.db_name} "
274-
f"user={self.db_user} password={self.db_password} sslmode={self.db_sslmode}"
280+
f"user={self.db_user} password={self.db_password} sslmode={self.db_sslmode} "
281+
"connect_timeout=10 keepalives=1 keepalives_idle=60 keepalives_interval=10 keepalives_count=3"
275282
)
276283

277284
@property

lik-ui/tests/test_run_scheduled_script.py

Lines changed: 42 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -108,6 +108,48 @@ def _blocks(*_args, **_kwargs):
108108
assert row["last_duration_s"] is not None # recorded even for the backstop path
109109

110110

111+
def test_terminal_write_is_retried_after_a_transient_db_failure(store, monkeypatch):
112+
"""The terminal write happens after a long stretch of no DB traffic, so it is the write most
113+
exposed to a dropped connection. A blip must be retried, not lost."""
114+
import scripts.run_scheduled as rs
115+
116+
monkeypatch.setattr(rs, "_RECORD_RETRY_BACKOFF_S", (0, 0, 0))
117+
a = store.upsert_user("a@navapbc.com")
118+
store.create_scheduled_run(a["id"], AGENT, "sync", timedelta(hours=1))
119+
real_complete = store.complete_run
120+
calls = {"n": 0}
121+
122+
def _flaky(*args, **kwargs):
123+
calls["n"] += 1
124+
if calls["n"] == 1:
125+
raise RuntimeError("couldn't get a connection after 5.00 sec")
126+
return real_complete(*args, **kwargs)
127+
128+
monkeypatch.setattr(store, "complete_run", _flaky)
129+
ran, failed = rs.run_due_schedules(store, FakeSessions([[{"type": "done"}]]), FakeVault(), _agents())
130+
assert (ran, failed) == (1, 0) # the retry recorded it, so this is not a job failure
131+
row = store.list_scheduled_runs(a["id"])[0]
132+
assert row["last_status"] == "success"
133+
assert row["started_at"] is None # advanced, not left in flight
134+
135+
136+
def test_unrecordable_outcome_counts_as_failure_without_aborting_the_scan(store, monkeypatch):
137+
"""When the outcome cannot be persisted at all, the scan still finishes the remaining rows and
138+
the job exits non-zero (the row stays in flight and is reclaimed next scan)."""
139+
import scripts.run_scheduled as rs
140+
141+
monkeypatch.setattr(rs, "_RECORD_RETRY_BACKOFF_S", (0, 0))
142+
a = store.upsert_user("a@navapbc.com")
143+
store.create_scheduled_run(a["id"], AGENT, "sync", timedelta(hours=1))
144+
145+
def _always_fails(*_args, **_kwargs):
146+
raise RuntimeError("couldn't get a connection after 5.00 sec")
147+
148+
monkeypatch.setattr(store, "complete_run", _always_fails)
149+
ran, failed = rs.run_due_schedules(store, FakeSessions([[{"type": "done"}]]), FakeVault(), _agents())
150+
assert (ran, failed) == (1, 1)
151+
152+
111153
def test_run_due_schedules_auth_lapse_pauses_and_counts_failure(store):
112154
a = store.upsert_user("a@navapbc.com")
113155
store.create_scheduled_run(a["id"], AGENT, "sync", timedelta(hours=1))

0 commit comments

Comments
 (0)