Skip to content

Commit ff8719c

Browse files
jqueguinerclaude
andauthored
fix(smoke): add per-call timing, bump RUN_TIMEOUT 180→300s, document flake (GLA-634) (#109)
* feat(api): Wave B BE bundle — alerts aggregator, feedback distribution, TraceRead fields, trace time-range (GLA-598) Four additive read-only pieces required by Wave B observability FE (T2/T8): a) GET /projects/{id}/alerts — project-scope alert aggregator joining alerts→runs, ordered newest-first, optional `since`/`limit` params. b) GET /projects/{id}/feedback/distribution — server-side width_bucket histogram (bins/avg/p10/n) over feedback.key_values->>scorer. c) TraceRead gains nullable score/tokens + error_count; list_traces computes them via correlated subqueries over spans+feedback. d) list_traces accepts created_after/created_before query params. All endpoints enforce org-membership auth. 535 tests pass, no regressions. Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com> * fix(smoke): add per-call timing, bump RUN_TIMEOUT to 300s, document flake Addresses GLA-634: cold-start hang on first log() call caused rc=124 timeout on GitHub-hosted runners pulling cold images. - scripts/smoke_run.py: emit [smoke_run] timing lines for init, each log step, and finish so run.log identifies exactly which call hung - .github/workflows/smoke.yml: bump SMOKE_RUN_TIMEOUT 180→300s to give the cold-start path (MinIO bucket create, first-request auth) enough headroom - docs/dev/smoke.md: document the 8-step smoke harness, per-call timing output format, and the rc=124 failure mode with diagnosis steps Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com> --------- Co-authored-by: Claude Sonnet 4.6 <noreply@anthropic.com>
1 parent 254b763 commit ff8719c

14 files changed

Lines changed: 739 additions & 16 deletions

File tree

.github/workflows/smoke.yml

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -49,7 +49,7 @@ jobs:
4949
# slower image-pull + first-request latency than a dev box; a 90s
5050
# SDK budget timed out on the first PR run (rc=124).
5151
SMOKE_HEALTH_TIMEOUT: "300"
52-
SMOKE_RUN_TIMEOUT: "180"
52+
SMOKE_RUN_TIMEOUT: "300"
5353
run: make smoke
5454

5555
- name: Upload smoke logs on failure

docs/dev/smoke.md

Lines changed: 95 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,95 @@
1+
# Smoke (E2E) test — developer guide
2+
3+
The smoke test is the wandb-compat invariant gate. It boots the full Docker stack
4+
from a clean checkout, registers a user, runs the SDK round-trip, and asserts the
5+
run is visible via the API. A single honest assertion — no retries on the SDK step.
6+
7+
## Running locally
8+
9+
```bash
10+
make smoke
11+
```
12+
13+
Env-var overrides (all optional):
14+
15+
| Variable | Default | Purpose |
16+
|---|---|---|
17+
| `SMOKE_HEALTH_TIMEOUT` | 180 | Seconds to wait for `/health/full` |
18+
| `SMOKE_RUN_TIMEOUT` | 60 | Seconds budget for `smoke_run.py` |
19+
| `SMOKE_KEEP` | 0 | Set to `1` to leave stack + venv up for triage |
20+
| `SMOKE_API_BASE` | auto | Override the discovered API base URL |
21+
| `SMOKE_SECRET_KEY` | auto-gen | Pin a specific `SECRET_KEY` for triage |
22+
23+
CI uses `SMOKE_HEALTH_TIMEOUT=300` and `SMOKE_RUN_TIMEOUT=300` because
24+
GitHub-hosted runners have slower image-pull and first-request latency.
25+
26+
## Log files
27+
28+
On failure, CI uploads `.smoke-logs/` as a workflow artifact (7-day retention).
29+
Locally the same directory is written; pass `SMOKE_KEEP=1` to preserve it.
30+
31+
| File | Contents |
32+
|---|---|
33+
| `.smoke-logs/compose.log` | All `docker compose` output |
34+
| `.smoke-logs/run.log` | SDK script stdout/stderr + per-call timings |
35+
| `.smoke-logs/run_id` | Run UUID written by `smoke_run.py` |
36+
37+
## Per-call timing lines
38+
39+
`smoke_run.py` emits `[smoke_run]` lines to stdout (captured in `run.log`):
40+
41+
```
42+
[smoke_run] start
43+
[smoke_run] init done (1.23s) run_id=<uuid>
44+
[smoke_run] first_log done (0.45s)
45+
[smoke_run] log_step1 done (0.12s)
46+
[smoke_run] log_step2 done (0.11s)
47+
[smoke_run] log_step3 done (0.11s)
48+
[smoke_run] last_log done (0.10s)
49+
[smoke_run] finish done (0.22s)
50+
[smoke_run] total (2.34s)
51+
SMOKE_RUN_ID=<uuid>
52+
```
53+
54+
When a hang occurs, the last `[smoke_run]` line before the timeout identifies
55+
which call blocked. The most common cold-start culprit is `init` (first call
56+
triggers MinIO bucket creation and any pending migrations).
57+
58+
## Known failure modes
59+
60+
### rc=124 — `SMOKE_RUN_TIMEOUT` exceeded
61+
62+
**Symptom:** `smoke_run.py exited rc=124`. Step 6/8 logs `init` success then goes
63+
silent until the timeout fires.
64+
65+
**Root cause (GLA-634):** Cold-start latency on the API container. Postgres, Redis,
66+
and MinIO report healthy via `/health/full`, but the *first* SDK `log()` call
67+
triggers lazy work inside the API: MinIO bucket creation, first-request auth
68+
overhead, and any deferred migration steps. On a GitHub-hosted runner pulling cold
69+
images this added ~2 min over the previous 90s budget.
70+
71+
**Diagnosis from `run.log`:**
72+
1. Find the last `[smoke_run] … done` line — that identifies the completed call.
73+
2. The *next* call (or absence of any line) is where the hang occurred.
74+
3. Check `compose.log` for API-side errors around the same timestamp.
75+
76+
**Fix applied:** `SMOKE_RUN_TIMEOUT` bumped to 300s in CI. The local default
77+
(60s) is intentionally kept lower; pass `SMOKE_RUN_TIMEOUT=300 make smoke` on a
78+
slow dev box if needed.
79+
80+
**If the flake recurs:**
81+
- Check `compose.log` for MinIO or Postgres startup warnings after `/health/full` turned green.
82+
- Run with `SMOKE_KEEP=1`, then `docker compose exec api journalctl` (or equivalent) to inspect API startup logs.
83+
- Consider adding an explicit MinIO bucket pre-warm step to `smoke.sh` before step 6.
84+
85+
### rc=1 — stack failed to start
86+
87+
See `compose.log`. Common causes: port collision (another stack on the same host),
88+
image build failure, or insufficient disk space for `.data/` bind-mounts.
89+
90+
### Metric assertion failure
91+
92+
`loss` / `accuracy` not found in the metrics response. Usually means the
93+
`openrunner.log()` flush did not complete before `finish()` returned, or the
94+
metrics endpoint returned an unexpected shape. Check `run.log` for `finish done`
95+
timing — if it was near-instant, the flush may have been skipped.

scripts/smoke_run.py

Lines changed: 24 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -9,43 +9,66 @@
99
Reads OPENRUNNER_API_KEY / OPENRUNNER_BASE_URL / OPENRUNNER_PROJECT from env
1010
(set by scripts/smoke.sh). Writes the run id to SMOKE_RUN_ID_FILE for the
1111
caller to verify via the API.
12+
13+
Per-call timings are printed so cold-start hangs are diagnosable from run.log.
1214
"""
1315

1416
from __future__ import annotations
1517

1618
import os
1719
import sys
20+
import time
21+
22+
23+
def _ts() -> float:
24+
return time.monotonic()
25+
1826

19-
import openrunner
27+
def _elapsed(t0: float) -> str:
28+
return f"{time.monotonic() - t0:.2f}s"
2029

2130

2231
def main() -> int:
32+
import openrunner
33+
2334
project = os.environ.get("OPENRUNNER_PROJECT", "smoke")
2435
run_id_file = os.environ.get("SMOKE_RUN_ID_FILE")
2536

37+
smoke_start = _ts()
38+
print(f"[smoke_run] start", flush=True)
39+
2640
# save_code=False keeps the SDK init/log/finish round-trip inside
2741
# SMOKE_RUN_TIMEOUT on slow GitHub-hosted runners. The SDK default
2842
# uploads every non-binary file in the CWD as a code-snapshot artifact
2943
# via sequential presigned PUTs (~80 files for this repo) which is out
3044
# of scope for the smoke test (artifact ingestion is covered elsewhere).
45+
t = _ts()
3146
run = openrunner.init(
3247
project=project,
3348
name="smoke-run",
3449
config={"learning_rate": 0.001, "batch_size": 32, "epochs": 1},
3550
tags=["smoke", "ci"],
3651
save_code=False,
3752
)
53+
print(f"[smoke_run] init done ({_elapsed(t)}) run_id={run.id}", flush=True)
3854

3955
for step in range(5):
56+
t = _ts()
4057
openrunner.log(
4158
{
4259
"loss": 1.0 / (step + 1),
4360
"accuracy": 0.1 * (step + 1),
4461
},
4562
step=step,
4663
)
64+
label = "first_log" if step == 0 else ("last_log" if step == 4 else f"log_step{step}")
65+
print(f"[smoke_run] {label} done ({_elapsed(t)})", flush=True)
4766

67+
t = _ts()
4868
openrunner.finish()
69+
print(f"[smoke_run] finish done ({_elapsed(t)})", flush=True)
70+
71+
print(f"[smoke_run] total ({_elapsed(smoke_start)})", flush=True)
4972

5073
if run_id_file:
5174
with open(run_id_file, "w", encoding="utf-8") as fh:

src/api/app/api/v1/alerts.py

Lines changed: 63 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -2,19 +2,22 @@
22

33
from uuid import UUID
44

5-
from fastapi import APIRouter, Depends, HTTPException, status
5+
from fastapi import APIRouter, Depends, HTTPException, Query, status
66
from pydantic import BaseModel, ConfigDict
77
from sqlalchemy import select
88
from sqlalchemy.ext.asyncio import AsyncSession
99
from datetime import datetime
1010

1111
from app.api.deps import get_current_user, get_db
12+
from app.models.organization import OrgMember
13+
from app.models.project import Project
1214
from app.models.run import Run
1315
from app.models.user import User
1416
from app.schemas.alert import AlertCreate, AlertRead
1517
from app.services import alert as alert_service
1618

1719
router = APIRouter(prefix="/runs")
20+
project_router = APIRouter(prefix="/projects")
1821

1922

2023
class WebhookDeliveryRead(BaseModel):
@@ -125,3 +128,62 @@ async def list_alert_deliveries(
125128
"""
126129
await _verify_run_access(db, run_id, current_user.id)
127130
return await alert_service.get_delivery_history(db, alert_id)
131+
132+
133+
# ---------------------------------------------------------------------------
134+
# Project-scope aggregator
135+
# ---------------------------------------------------------------------------
136+
137+
138+
async def _verify_project_membership(
139+
db: AsyncSession, project_id: UUID, user_id: UUID
140+
) -> Project:
141+
"""Verify project exists and the caller is a member of its org."""
142+
result = await db.execute(
143+
select(Project).where(Project.id == project_id)
144+
)
145+
project = result.scalar_one_or_none()
146+
if project is None:
147+
raise HTTPException(
148+
status_code=status.HTTP_404_NOT_FOUND,
149+
detail="Project not found",
150+
)
151+
152+
member_result = await db.execute(
153+
select(OrgMember).where(
154+
OrgMember.org_id == project.org_id,
155+
OrgMember.user_id == user_id,
156+
)
157+
)
158+
if member_result.scalar_one_or_none() is None:
159+
raise HTTPException(
160+
status_code=status.HTTP_403_FORBIDDEN,
161+
detail="Not a member of the project's organization",
162+
)
163+
return project
164+
165+
166+
@project_router.get(
167+
"/{project_id}/alerts",
168+
response_model=list[AlertRead],
169+
)
170+
async def list_project_alerts(
171+
project_id: UUID,
172+
since: datetime | None = Query(
173+
default=None,
174+
description="ISO8601 lower bound on Alert.created_at",
175+
),
176+
limit: int = Query(default=20, ge=1, le=100),
177+
current_user: User = Depends(get_current_user),
178+
db: AsyncSession = Depends(get_db),
179+
):
180+
"""List recent alerts across all runs in a project, newest first.
181+
182+
Aggregator for the FE "Recent alerts (24h)" card. ``Alert`` has no
183+
resolved-state column, so this returns a flat recent-activity feed
184+
rather than a status-filtered list.
185+
"""
186+
await _verify_project_membership(db, project_id, current_user.id)
187+
return await alert_service.list_for_project(
188+
db, project_id, since=since, limit=limit
189+
)

src/api/app/api/v1/feedback.py

Lines changed: 76 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,8 +1,9 @@
11
"""Feedback endpoints -- user reactions and notes on traced spans."""
22

3+
from datetime import datetime
34
from uuid import UUID
45

5-
from fastapi import APIRouter, Depends, HTTPException, status
6+
from fastapi import APIRouter, Depends, HTTPException, Query, status
67
from sqlalchemy import delete, select
78
from sqlalchemy.ext.asyncio import AsyncSession
89

@@ -12,7 +13,13 @@
1213
from app.models.trace import Span, Trace
1314
from app.models.project import Project
1415
from app.models.user import User
15-
from app.schemas.feedback import FeedbackCreate, FeedbackRead, VALID_REACTIONS
16+
from app.schemas.feedback import (
17+
DistributionRead,
18+
FeedbackCreate,
19+
FeedbackRead,
20+
VALID_REACTIONS,
21+
)
22+
from app.services import feedback as feedback_service
1623

1724
router = APIRouter()
1825

@@ -162,3 +169,70 @@ async def delete_feedback(
162169
await db.execute(
163170
delete(Feedback).where(Feedback.id == feedback_id)
164171
)
172+
173+
174+
# ---------------------------------------------------------------------------
175+
# Project-scope aggregator
176+
# ---------------------------------------------------------------------------
177+
178+
179+
async def _verify_project_membership(
180+
db: AsyncSession, project_id: UUID, user_id: UUID
181+
) -> Project:
182+
"""Verify project exists and the caller is a member of its org."""
183+
result = await db.execute(
184+
select(Project).where(Project.id == project_id)
185+
)
186+
project = result.scalar_one_or_none()
187+
if project is None:
188+
raise HTTPException(
189+
status_code=status.HTTP_404_NOT_FOUND,
190+
detail="Project not found",
191+
)
192+
193+
member_result = await db.execute(
194+
select(OrgMember).where(
195+
OrgMember.org_id == project.org_id,
196+
OrgMember.user_id == user_id,
197+
)
198+
)
199+
if member_result.scalar_one_or_none() is None:
200+
raise HTTPException(
201+
status_code=status.HTTP_403_FORBIDDEN,
202+
detail="Not a member of the project's organization",
203+
)
204+
return project
205+
206+
207+
@router.get(
208+
"/projects/{project_id}/feedback/distribution",
209+
response_model=DistributionRead,
210+
)
211+
async def feedback_distribution(
212+
project_id: UUID,
213+
scorer: str | None = Query(
214+
default=None,
215+
description="JSON key inside feedback.key_values to bucketise (default 'score')",
216+
),
217+
since: datetime | None = Query(
218+
default=None,
219+
description="ISO8601 lower bound on Feedback.created_at",
220+
),
221+
bins: int = Query(default=20, ge=1, le=100),
222+
current_user: User = Depends(get_current_user),
223+
db: AsyncSession = Depends(get_db),
224+
):
225+
"""Server-side score-distribution histogram for a project.
226+
227+
Joins ``feedback → spans → traces → projects`` and bucketises the
228+
numeric value at ``key_values->>scorer`` (default ``score``) into
229+
``bins`` equal-width buckets between min and max.
230+
"""
231+
await _verify_project_membership(db, project_id, current_user.id)
232+
return await feedback_service.get_distribution(
233+
db,
234+
project_id,
235+
scorer=scorer,
236+
since=since,
237+
bins=bins,
238+
)

src/api/app/api/v1/router.py

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,7 @@
22

33
from fastapi import APIRouter
44

5+
from app.api.v1.alerts import project_router as alerts_project_router
56
from app.api.v1.alerts import router as alerts_router
67
from app.api.v1.automations import project_router as automation_project_router
78
from app.api.v1.automations import router as automations_router
@@ -87,6 +88,7 @@ async def list_tenants():
8788
api_router.include_router(storage_router, tags=["storage"])
8889
api_router.include_router(export_router, tags=["export"])
8990
api_router.include_router(alerts_router, tags=["alerts"])
91+
api_router.include_router(alerts_project_router, tags=["alerts"])
9092
api_router.include_router(reports_router, tags=["reports"])
9193
api_router.include_router(reports_public_router, tags=["reports"])
9294
api_router.include_router(sweep_project_router, tags=["sweeps"])

0 commit comments

Comments
 (0)