Rifqi Hafizuddin Claude Opus 4.8 commited on
Commit
735c421
·
1 Parent(s): d7dad60

[NOTICKET] perf(slow-path): DB3 pre-connect + R4 progress events

Browse files

DB3 (DB owner): DbExecutor.prewarm(catalog, user_id) warms the pooled engine for
schema sources, fired (best-effort, never raises) at slow-path entry so the cold
first-query TCP+TLS+auth handshake overlaps the ~4s Planner LLM call. Gated to the
default path (skipped when a coordinator factory is injected, so tests stay
hermetic). Reuses DbExecutor's existing client resolution + the DB2 engine cache.

R4 (agent): SlowPathCoordinator.run gained an optional `progress` callback;
ChatHandler bridges it to SSE `status` events via an asyncio queue, and chat.py
forwards them. The slow path no longer streams ~13s of silence — live timeline now
shows Planning -> Running N steps -> Composing, max wire gap ~4.6s, fixing proxy
idle-timeout + UX. Status events only appear when the coordinator calls back, so the
existing wiring test's event sequence is unchanged (fake coordinator just accepts
**kwargs). Token-streaming the Assembler answer is deferred: it would require
splitting the Assembler into a streamed prose call + a structured-record call,
doubling its LLM calls (cost/latency) - a separate decision.

Verified live through ChatHandler.handle against the real user DB. 114 tests pass.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>

PROGRESS.md CHANGED
@@ -42,8 +42,8 @@ Verified against code before logging. Severity: **critical** / important / nice-
42
  | R3 | **Commit `tests/` + minimal CI** — `tests/` is gitignored; the 200+ tests cited as done exist only on laptops (already caused rename rot). GitHub origin carries tests; HF Space gets the Docker build (already doesn't COPY tests). | **critical (process)** | shared | `[ ]` |
43
  | DB1 | **In-memory `describe_source`** (request-scoped `MemoizingCatalogReader`, `reader.py`) + **LLM-client hoist** (shared module-level `ChatHandler` in `chat.py`). Measured live: `describe_source` 3.5s→~2.0s (structured read now served from the planner's cached snapshot; only the unstructured read remains a round-trip), catalog reads/request ~5→~2. External `query_structured` handshake unchanged (DB2's job) so total slow path is ~flat until DB2. Tests: `tests/catalog/test_reader.py`. | important | agent | `[x]` |
44
  | DB2 | **Keyed engine cache** — `src/database_client/engine.py::UserEngineCache` (process singleton): pooled engines keyed by `client_id + creds-hash` (rotation auto-invalidates), bounded LRU (50) + 600s idle TTL, `pool_pre_ping` + `pool_recycle=300`. `DbExecutor._run_sync` reuses the warm connection instead of `create_engine→connect→dispose` per query (postgres/supabase only; other db_types keep the legacy path — no regression). **Live-measured: warm `query_structured` 6.6–9.4s → ~2.5s** (the residual is the per-call catalog-DB client fetch + pre-ping, not the external handshake). **Finding:** Neon's transaction pooler REJECTS `default_transaction_read_only` as a libpq startup `option` — caught live; moved read-only + statement_timeout to a per-connection `connect` event (best-effort; authoritative read-only is the SELECT-only compiler + sqlglot guard, see R10). Per-request ownership/active check kept. Proceeded ahead of R1 per owner decision (marginal security delta over the existing no-auth state; auth tracked separately). Tests: `tests/database_client/test_engine.py`. First query/process still cold → DB3. | important | DB | `[x]` |
45
- | DB3 | **Speculative pre-connect** overlapped with the ~4s Planner call (only if DB2 still shows first-touch handshake). | nice-to-have | DB | `[ ]` |
46
- | R4 | **Stream the Assembler + emit TaskRunner progress events** slow path streams nothing for ~20s (`chat_handler.py:321` single chunk); proxy idle-timeout + UX risk. | important | agent | `[ ]` |
47
  | R5 | **Response cache**: key on `user_id` + catalog version; invalidate on ingest. Today `chat:{room_id}:{message}`, 24h TTL, no user (`chat.py:138`) → cross-room replay + stale answers. | important | B | `[ ]` |
48
  | R6 | **Hard time budget** — wrap `coordinator.run()` in `asyncio.wait_for` (60–90s). `Constraints.time_budget_seconds` is rendered but not enforced. | important | agent | `[ ]` |
49
  | R7 | **Root-task-failure short-circuit** before the Assembler (templated/fast-path fallback, NOT replanning) — stops paying ~2k tok to narrate an empty RunState. | important | agent | `[ ]` |
 
42
  | R3 | **Commit `tests/` + minimal CI** — `tests/` is gitignored; the 200+ tests cited as done exist only on laptops (already caused rename rot). GitHub origin carries tests; HF Space gets the Docker build (already doesn't COPY tests). | **critical (process)** | shared | `[ ]` |
43
  | DB1 | **In-memory `describe_source`** (request-scoped `MemoizingCatalogReader`, `reader.py`) + **LLM-client hoist** (shared module-level `ChatHandler` in `chat.py`). Measured live: `describe_source` 3.5s→~2.0s (structured read now served from the planner's cached snapshot; only the unstructured read remains a round-trip), catalog reads/request ~5→~2. External `query_structured` handshake unchanged (DB2's job) so total slow path is ~flat until DB2. Tests: `tests/catalog/test_reader.py`. | important | agent | `[x]` |
44
  | DB2 | **Keyed engine cache** — `src/database_client/engine.py::UserEngineCache` (process singleton): pooled engines keyed by `client_id + creds-hash` (rotation auto-invalidates), bounded LRU (50) + 600s idle TTL, `pool_pre_ping` + `pool_recycle=300`. `DbExecutor._run_sync` reuses the warm connection instead of `create_engine→connect→dispose` per query (postgres/supabase only; other db_types keep the legacy path — no regression). **Live-measured: warm `query_structured` 6.6–9.4s → ~2.5s** (the residual is the per-call catalog-DB client fetch + pre-ping, not the external handshake). **Finding:** Neon's transaction pooler REJECTS `default_transaction_read_only` as a libpq startup `option` — caught live; moved read-only + statement_timeout to a per-connection `connect` event (best-effort; authoritative read-only is the SELECT-only compiler + sqlglot guard, see R10). Per-request ownership/active check kept. Proceeded ahead of R1 per owner decision (marginal security delta over the existing no-auth state; auth tracked separately). Tests: `tests/database_client/test_engine.py`. First query/process still cold → DB3. | important | DB | `[x]` |
45
+ | DB3 | **Speculative pre-connect** `DbExecutor.prewarm(catalog, user_id)` warms the pooled engine for schema sources (fire-and-forget at slow-path entry) so the cold first-query handshake overlaps the ~4s Planner call. Best-effort, never raises; gated to the default path (skipped when a coordinator factory is injected). Verified live through `ChatHandler.handle`. | nice-to-have | DB | `[x]` |
46
+ | R4 | **Per-stage progress events** `SlowPathCoordinator.run` gained an optional `progress` callback; `ChatHandler` bridges it to SSE `status` events (`chat.py` forwards them). Live: stream now shows `Planning…`→`Running N steps…`→`Composing…` (max wire gap ~4.6s, was ~13s of silence) → fixes proxy idle-timeout + UX. **Deferred:** token-streaming the Assembler answer needs splitting it into a streamed prose call + a structured-record call — that doubles the Assembler LLM calls (cost/latency), so it's a separate decision; the answer is still emitted as one chunk after the (fast ~2.5s) Assembler. Test: `test_chat_handler_wiring.py`. | important | agent | `[~]` |
47
  | R5 | **Response cache**: key on `user_id` + catalog version; invalidate on ingest. Today `chat:{room_id}:{message}`, 24h TTL, no user (`chat.py:138`) → cross-room replay + stale answers. | important | B | `[ ]` |
48
  | R6 | **Hard time budget** — wrap `coordinator.run()` in `asyncio.wait_for` (60–90s). `Constraints.time_budget_seconds` is rendered but not enforced. | important | agent | `[ ]` |
49
  | R7 | **Root-task-failure short-circuit** before the Assembler (templated/fast-path fallback, NOT replanning) — stops paying ~2k tok to narrate an empty RunState. | important | agent | `[ ]` |
src/agents/chat_handler.py CHANGED
@@ -22,6 +22,7 @@ inject mocks).
22
 
23
  from __future__ import annotations
24
 
 
25
  import json
26
  from collections.abc import AsyncIterator, Callable
27
  from typing import TYPE_CHECKING, Any
@@ -311,6 +312,15 @@ class ChatHandler:
311
 
312
  coordinator = self._get_slow_path_coordinator(user_id, tracer, catalog_reader)
313
  context = await get_business_context(user_id)
 
 
 
 
 
 
 
 
 
314
  pc = tracer.callbacks() # planner: PII-safe, full capture
315
  ac = tracer.callbacks(masked=True) # assembler: sees real rows -> masked
316
  run_kw: dict[str, Any] = {}
@@ -318,8 +328,38 @@ class ChatHandler:
318
  run_kw["planner_callbacks"] = pc
319
  if ac:
320
  run_kw["assembler_callbacks"] = ac
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
321
  try:
322
- result = await coordinator.run(context, catalog, query, Constraints(), **run_kw)
323
  except Exception as e:
324
  logger.error("slow path failed", user_id=user_id, error=str(e))
325
  yield {"event": "error", "data": f"Analysis failed: {e}"}
 
22
 
23
  from __future__ import annotations
24
 
25
+ import asyncio
26
  import json
27
  from collections.abc import AsyncIterator, Callable
28
  from typing import TYPE_CHECKING, Any
 
312
 
313
  coordinator = self._get_slow_path_coordinator(user_id, tracer, catalog_reader)
314
  context = await get_business_context(user_id)
315
+
316
+ # DB3: warm the user's DB connection in parallel with planning so the
317
+ # handshake overlaps the ~4s Planner call. Default path only — an injected
318
+ # coordinator factory (tests / custom) may not use the real DbExecutor.
319
+ if self._slow_path_factory is None:
320
+ from ..query.executor.db import DbExecutor
321
+
322
+ asyncio.create_task(DbExecutor.prewarm(catalog, user_id)) # noqa: RUF006
323
+
324
  pc = tracer.callbacks() # planner: PII-safe, full capture
325
  ac = tracer.callbacks(masked=True) # assembler: sees real rows -> masked
326
  run_kw: dict[str, Any] = {}
 
328
  run_kw["planner_callbacks"] = pc
329
  if ac:
330
  run_kw["assembler_callbacks"] = ac
331
+
332
+ # R4: bridge the coordinator's per-stage progress callback to SSE `status`
333
+ # events so the stream isn't silent for ~12s (and proxies don't drop the
334
+ # idle connection). Status events only appear if the coordinator calls back.
335
+ progress_q: asyncio.Queue[str] = asyncio.Queue()
336
+
337
+ async def _progress(stage: str) -> None:
338
+ await progress_q.put(stage)
339
+
340
+ run_task = asyncio.create_task(
341
+ coordinator.run(
342
+ context, catalog, query, Constraints(), progress=_progress, **run_kw
343
+ )
344
+ )
345
+ getter: asyncio.Task = asyncio.create_task(progress_q.get())
346
+ pending: set[asyncio.Task] = {run_task, getter}
347
+ while True:
348
+ done, pending = await asyncio.wait(
349
+ pending, return_when=asyncio.FIRST_COMPLETED
350
+ )
351
+ if getter in done:
352
+ yield {"event": "status", "data": getter.result()}
353
+ getter = asyncio.create_task(progress_q.get())
354
+ pending = pending | {getter}
355
+ if run_task in done:
356
+ getter.cancel()
357
+ while not progress_q.empty():
358
+ yield {"event": "status", "data": progress_q.get_nowait()}
359
+ break
360
+
361
  try:
362
+ result = run_task.result()
363
  except Exception as e:
364
  logger.error("slow path failed", user_id=user_id, error=str(e))
365
  yield {"event": "error", "data": f"Analysis failed: {e}"}
src/agents/slow_path/coordinator.py CHANGED
@@ -10,6 +10,8 @@ See AGENT_ARCHITECTURE_CONTEXT_new.md §5.2 / §6.1.
10
 
11
  from __future__ import annotations
12
 
 
 
13
  from ...catalog.models import Catalog
14
  from ..planner.contracts import BusinessContext, ToolRegistry
15
  from ..planner.inputs import Constraints
@@ -40,14 +42,24 @@ class SlowPathCoordinator:
40
  constraints: Constraints,
41
  planner_callbacks: list | None = None,
42
  assembler_callbacks: list | None = None,
 
43
  ) -> AssembledOutput:
 
 
 
 
 
44
  plan_kw = {"callbacks": planner_callbacks} if planner_callbacks else {}
45
  task_list = await self._planner.plan(
46
  context, catalog, self._registry, query, constraints, **plan_kw
47
  )
 
 
48
  run_state = await self._task_runner.run(
49
  task_list, business_context_id=context.project_id
50
  )
 
 
51
  asm_kw = {"callbacks": assembler_callbacks} if assembler_callbacks else {}
52
  return await self._assembler.assemble(
53
  run_state, context, question=query, **asm_kw
 
10
 
11
  from __future__ import annotations
12
 
13
+ from collections.abc import Awaitable, Callable
14
+
15
  from ...catalog.models import Catalog
16
  from ..planner.contracts import BusinessContext, ToolRegistry
17
  from ..planner.inputs import Constraints
 
42
  constraints: Constraints,
43
  planner_callbacks: list | None = None,
44
  assembler_callbacks: list | None = None,
45
+ progress: Callable[[str], Awaitable[None]] | None = None,
46
  ) -> AssembledOutput:
47
+ # `progress` (optional) surfaces per-stage status to the caller so a long
48
+ # slow-path run isn't a silent ~12s on the wire. Each stage is a single
49
+ # awaitable, so the most granular signal we can emit is at stage boundaries.
50
+ if progress:
51
+ await progress("Planning the analysis…")
52
  plan_kw = {"callbacks": planner_callbacks} if planner_callbacks else {}
53
  task_list = await self._planner.plan(
54
  context, catalog, self._registry, query, constraints, **plan_kw
55
  )
56
+ if progress:
57
+ await progress(f"Running {len(task_list.tasks)} analysis steps…")
58
  run_state = await self._task_runner.run(
59
  task_list, business_context_id=context.project_id
60
  )
61
+ if progress:
62
+ await progress("Composing the answer…")
63
  asm_kw = {"callbacks": assembler_callbacks} if assembler_callbacks else {}
64
  return await self._assembler.assemble(
65
  run_state, context, question=query, **asm_kw
src/api/v1/chat.py CHANGED
@@ -199,6 +199,10 @@ async def chat_stream(request: ChatRequest, db: AsyncSession = Depends(get_db)):
199
  except Exception as e:
200
  logger.error("save_messages failed", room_id=request.room_id, error=str(e))
201
  yield event
 
 
 
 
202
  elif event["event"] == "error":
203
  yield event
204
  return
 
199
  except Exception as e:
200
  logger.error("save_messages failed", room_id=request.room_id, error=str(e))
201
  yield event
202
+ elif event["event"] == "status":
203
+ # slow-path progress ("Planning…", "Running N steps…"): forward
204
+ # so the client shows activity and the SSE connection stays alive.
205
+ yield event
206
  elif event["event"] == "error":
207
  yield event
208
  return
src/query/executor/db.py CHANGED
@@ -197,9 +197,9 @@ class DbExecutor(BaseExecutor):
197
  engine = user_engine_cache.get_engine(client_id, db_type, creds)
198
  if engine is not None:
199
  # Pooled, reused engine (postgres-like). Read-only + statement_timeout
200
- # are pinned at connection establishment (connect_args options), so no
201
- # per-query SET round-trips and no dispose — the connection returns to
202
- # the pool warm for the next query.
203
  with engine.connect() as conn:
204
  result = conn.execute(text(compiled.sql), compiled.params)
205
  return list(result.keys()), [dict(row) for row in result.mappings()]
@@ -210,3 +210,38 @@ class DbExecutor(BaseExecutor):
210
  with eng.connect() as conn:
211
  result = conn.execute(text(compiled.sql), compiled.params)
212
  return list(result.keys()), [dict(row) for row in result.mappings()]
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
197
  engine = user_engine_cache.get_engine(client_id, db_type, creds)
198
  if engine is not None:
199
  # Pooled, reused engine (postgres-like). Read-only + statement_timeout
200
+ # are set once per physical connection (connect event in UserEngineCache),
201
+ # so no per-query SET round-trips and no dispose — the connection returns
202
+ # to the pool warm for the next query.
203
  with engine.connect() as conn:
204
  result = conn.execute(text(compiled.sql), compiled.params)
205
  return list(result.keys()), [dict(row) for row in result.mappings()]
 
210
  with eng.connect() as conn:
211
  result = conn.execute(text(compiled.sql), compiled.params)
212
  return list(result.keys()), [dict(row) for row in result.mappings()]
213
+
214
+ # ------------------------------------------------------------------
215
+ # Speculative pre-connect (DB3)
216
+ # ------------------------------------------------------------------
217
+
218
+ @classmethod
219
+ async def prewarm(cls, catalog: Catalog, user_id: str) -> None:
220
+ """Best-effort: warm pooled engines for the catalog's schema sources.
221
+
222
+ Called at slow-path entry so the TCP+TLS+auth handshake overlaps the ~4s
223
+ Planner LLM call — by the time `query_structured` runs, the connection is
224
+ already established. Warming is an optimization, never a requirement, so
225
+ this never raises and per-source failures are swallowed.
226
+ """
227
+ for source in catalog.sources:
228
+ if source.source_type != "schema":
229
+ continue
230
+ try:
231
+ client_id = cls._parse_client_id(source.location_ref)
232
+ client = await cls._fetch_client(client_id)
233
+ if client.user_id != user_id:
234
+ continue
235
+ creds = decrypt_credentials_dict(client.credentials)
236
+ await asyncio.to_thread(cls._warm_sync, client_id, client.db_type, creds)
237
+ except Exception as exc: # noqa: BLE001 — best-effort warming
238
+ logger.info("prewarm skipped", source_id=source.source_id, error=str(exc))
239
+
240
+ @staticmethod
241
+ def _warm_sync(client_id: str, db_type: str, creds: dict) -> None:
242
+ engine = user_engine_cache.get_engine(client_id, db_type, creds)
243
+ if engine is not None:
244
+ # Open + return a pooled physical connection: forces the handshake and
245
+ # runs the connect-event session SETs, leaving the pool warm.
246
+ with engine.connect():
247
+ pass