**SQLite is the database, and now says so.** `metric_minute` and every run
table are written with `sqlalchemy.dialects.sqlite.insert(...)
.on_conflict_do_update` and with `max(a, b)`, neither of which another
dialect has — so pointing `DATABASE_URL` at Postgres migrated cleanly,
served, logged in, and then lost every observability flush into the
collector's hold buffer and failed every run. It refuses at startup
instead. (The Postgres in the compose stack is Umami's; the engine's own
database has been a file beside the flows since 2026-08-21.)
**Every integer query parameter is bounded.** The caps were written as
`min(limit, 500)`, which a negative walks straight through — `?limit=-1`
compiles to `LIMIT -1` and SQLite returns the whole table. Ten signatures,
now `Query(ge=…, le=…)`. `hours=0` still means an hour, which
`_window_hours` was already deliberate about.
**Exports are capped at 10 000 runs** and say so with `X-Truncated`. The
filters bounded a sensible request and nothing bounded an unfiltered one,
which read every row into memory before a byte was streamed. `_series`
resolves cached curves in two queries rather than a `Run` lookup and a
`RunMetric` query per restored node — a comparison of twenty runs was
calling that twenty times over.
**`PUT /artifacts` has a size limit** (`MAX_ARTIFACT_BYTES`, 2 GiB, 0 to
disable), checked against `Content-Length` and again against the stream for
a chunked body, and its writes moved off the event loop.
**`/observability/timeseries` takes `since`/`until`**, the same window
`/runs` and `/events` take, capped at 2000 points — `hours=720&bucket_s=60`
was 43 200 of them in one array. It is also what a dragged chart needs to
re-fetch at its own resolution rather than magnifying buckets it has.
**Composite indexes** for the three list screens: `run(flow, created_at)`
and `(status, created_at)`, `flow_run(flow, started_at)`,
`engine_event(type, ts)`. Every index was single-column, so SQLite picked
one and sorted the rest by hand. Verified against a copy of a live database
(250k `flow_run` rows): the planner takes all four.
**Redis clients have socket timeouts.** A Redis that stops answering
without closing the connection hung the caller until the kernel gave up —
including `/utils/health/`, whose job is to notice.
**The panels file is written under one lock.** `save_panels` and
`unpair_panel` are both read-modify-write, and a save that read before an
unpair wrote put the old nonce back — silently un-revoking a screen that
had just been unpaired. The nonce carry-forward was written to make that
impossible; the gap between its read and its write is where it happened.
**Startup releases what it acquired.** Everything past `event_bus.bind`
registers how to close itself and the `finally` walks that list backwards;
a failure part-way through used to reach none of the shutdown steps and
leave the worker pool's subprocesses and every background task behind —
under `--reload`, once per bad edit. `modules.reconcile` moved into the
background: `uv` gets five minutes twice over, the healthcheck allows
eighty seconds, and the autoheal restarted the container before it could
finish installing.
`delete_run` takes SQLite's write lock up front (`core.db.writing`) rather
than upgrading a deferred transaction and losing to whichever flush
committed in between. `modules.sync` is serialised — two applies mutated
one venv at once. The proxied-call and stream dicts are bounded, and a
reused id cancels its predecessor instead of dropping the reference.
Security, found in passing and small enough to fix here:
- **`/secrets/` required only a signed-in user.** The names alone say what
this installation talks to, and `PUT /{name}` takes any name, so any
account could overwrite the credential a flow authenticates with.
Superuser now — which `/search` already assumed and said so.
- **`POST /login/access-token` had no rate limit.** Argon2 is deliberately
expensive and the route is unauthenticated and runs in the shared
threadpool. Ten *failed* attempts per address per five minutes; a
successful sign-in spends nothing.
- **a password reset link worked repeatedly for 48 hours.** The token now
carries a digest of the password hash it was minted against, so it stops
verifying once it has set one. No table of spent tokens needed.
- **enrolment accepted `http://`**, sending the claim code and then this
installation's credential in clear. https, or a local address.
- the rate limiter read `request.client.host`, which behind Traefik is the
proxy — so every per-address limit was one global bucket and one caller
could lock out everyone. It reads the forwarded address, and its
bucket table is capped rather than growing one key per address forever.
- SMTP has a timeout and sends after the response, so an unreachable mail
host cannot pin a threadpool worker, and a reply's timing no longer says
whether the address exists.
Test suite: engine-written rows are cleared between modules. A `FlowRun`
left `running` by one module turned up in another's query. Per-test
rollback is not available here — the module-scoped `client` runs the real
lifespan and its collector and run service write through sessions of their
own — so this bounds it where the writes come from. Three consecutive
green runs, orders randomised.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01M6hPWS6YEbT1P8LxhhFb2T
450 lines
15 KiB
Python
450 lines
15 KiB
Python
from datetime import UTC, datetime, timedelta
|
|
|
|
from fastapi.testclient import TestClient
|
|
from sqlmodel import Session
|
|
|
|
from fluksio.core.config import settings
|
|
from fluksio.models import EngineEvent, FlowRun, MetricBucket
|
|
|
|
PREFIX = f"{settings.API_V1_STR}/observability"
|
|
FLOW = "observability-test"
|
|
|
|
|
|
def _seed(db: Session) -> None:
|
|
now = datetime.now(UTC).replace(second=0, microsecond=0)
|
|
db.add(
|
|
MetricBucket(
|
|
flow=FLOW,
|
|
node=f"{FLOW}.calc",
|
|
bucket=now - timedelta(minutes=1),
|
|
executions=4,
|
|
errors=1,
|
|
messages=6,
|
|
duration_sum_ms=40.0,
|
|
duration_max_ms=25.0,
|
|
lag_sum_ms=100.0,
|
|
lag_max_ms=60.0,
|
|
items=4,
|
|
)
|
|
)
|
|
db.add(
|
|
EngineEvent(
|
|
ts=now,
|
|
type="node_error",
|
|
flow=FLOW,
|
|
node=f"{FLOW}.calc",
|
|
detail="ValueError: bad input\nTraceback",
|
|
)
|
|
)
|
|
db.add(
|
|
EngineEvent(
|
|
ts=now, type="audit", flow=FLOW, detail="published", actor="a@example.com"
|
|
)
|
|
)
|
|
db.add(
|
|
FlowRun(
|
|
id="9-0",
|
|
flow=FLOW,
|
|
source="external",
|
|
started_at=now,
|
|
finished_at=now,
|
|
status="ok",
|
|
nodes=3,
|
|
duration_ms=12.5,
|
|
)
|
|
)
|
|
db.commit()
|
|
|
|
|
|
def test_observability_requires_authentication(client: TestClient) -> None:
|
|
assert client.get(f"{PREFIX}/summary").status_code == 401
|
|
|
|
|
|
def test_the_summary_answers_even_when_degraded(
|
|
client: TestClient, superuser_token_headers: dict[str, str]
|
|
) -> None:
|
|
response = client.get(f"{PREFIX}/summary", headers=superuser_token_headers)
|
|
|
|
assert response.status_code == 200
|
|
body = response.json()
|
|
assert body["status"] in {"ok", "degraded"}
|
|
assert set(body["flows"]) == {
|
|
"total",
|
|
"running",
|
|
"paused",
|
|
"quarantined",
|
|
"invalid",
|
|
}
|
|
assert "error" in body["nodes"]
|
|
# A windowed count comes from /flows?hours= now, which is what the tile
|
|
# that used to read this actually sums.
|
|
assert "failures_24h" not in body
|
|
|
|
|
|
def test_a_flow_that_cannot_run_makes_the_summary_degraded(
|
|
client: TestClient, superuser_token_headers: dict[str, str]
|
|
) -> None:
|
|
"""A loop on the canvas has to reach the health screen.
|
|
|
|
Validation runs on a build, not on this request, so what the engine already
|
|
knows is what this reports — and reporting it is the whole point: a flow
|
|
with a dependency loop cannot run, and the screen used to say "ok".
|
|
"""
|
|
from fluksio.flow.pipeline import ValidationIssue
|
|
|
|
controller = client.app.state.flow_controller
|
|
before = controller.issues
|
|
before_flows = controller.store.list_flows
|
|
# The looping flow has to be one the store lists, otherwise "running"
|
|
# counts nothing either way and the assertion below proves nothing.
|
|
controller.store.list_flows = lambda: ["looping"]
|
|
controller.issues = [
|
|
ValidationIssue(
|
|
code="cycle",
|
|
message="These nodes depend on each other in a loop",
|
|
flow="looping",
|
|
nodes=["looping.a", "looping.b"],
|
|
),
|
|
# Already counted as a node that failed to load, so not again here.
|
|
ValidationIssue(
|
|
code="node_error", message="boom", flow="broken", node="broken.x"
|
|
),
|
|
ValidationIssue(
|
|
code="unauthenticated_hook", message="open", flow="hooky", node="hooky.h"
|
|
),
|
|
]
|
|
try:
|
|
body = client.get(f"{PREFIX}/summary", headers=superuser_token_headers).json()
|
|
finally:
|
|
controller.issues = before
|
|
controller.store.list_flows = before_flows
|
|
|
|
assert body["status"] == "degraded"
|
|
assert body["flows"]["invalid"] == 1
|
|
assert body["flows"]["running"] == 0
|
|
assert any("looping" in problem for problem in body["problems"])
|
|
assert not any("broken" in problem for problem in body["problems"])
|
|
assert not any("hooky" in problem for problem in body["problems"])
|
|
|
|
|
|
def test_a_down_node_makes_the_summary_degraded(
|
|
client: TestClient, superuser_token_headers: dict[str, str]
|
|
) -> None:
|
|
"""A connector that cannot reach its device is not a flow that cannot run.
|
|
|
|
It is counted on its own, so the flow keeps running and "invalid" stays
|
|
about validation.
|
|
"""
|
|
from fluksio.flow.controller import LoadedNode
|
|
|
|
controller = client.app.state.flow_controller
|
|
before = controller.loaded
|
|
controller.loaded = {
|
|
"house.owm": LoadedNode(
|
|
id="house.owm",
|
|
flow="house",
|
|
health="down",
|
|
health_detail="ConnectionError: name resolution failed",
|
|
)
|
|
}
|
|
try:
|
|
body = client.get(f"{PREFIX}/summary", headers=superuser_token_headers).json()
|
|
finally:
|
|
controller.loaded = before
|
|
|
|
assert body["status"] == "degraded"
|
|
assert body["nodes"]["unhealthy"] == 1
|
|
assert any("down" in problem for problem in body["problems"])
|
|
assert body["flows"]["invalid"] == 0
|
|
|
|
|
|
def test_the_history_reads_back(
|
|
client: TestClient, superuser_token_headers: dict[str, str], db: Session
|
|
) -> None:
|
|
_seed(db)
|
|
|
|
points = client.get(f"{PREFIX}/timeseries", headers=superuser_token_headers).json()
|
|
mine = [point for point in points if point["executions"]]
|
|
assert mine and mine[-1]["avg_ms"] > 0
|
|
|
|
flows = client.get(f"{PREFIX}/flows", headers=superuser_token_headers).json()
|
|
row = next(entry for entry in flows if entry["flow"] == FLOW)
|
|
assert (row["executions"], row["errors"], row["messages"]) == (4, 1, 6)
|
|
assert len(row["spark"]) == 60
|
|
assert row["last_error_ts"] is not None
|
|
|
|
runs = client.get(f"{PREFIX}/runs", headers=superuser_token_headers).json()
|
|
assert any(run["id"] == "9-0" and run["status"] == "ok" for run in runs["data"])
|
|
|
|
failures = client.get(f"{PREFIX}/events", headers=superuser_token_headers).json()
|
|
assert any("Traceback" in event["detail"] for event in failures)
|
|
assert all(event["type"] != "audit" for event in failures)
|
|
|
|
audit = client.get(
|
|
f"{PREFIX}/events", headers=superuser_token_headers, params={"kind": "audit"}
|
|
).json()
|
|
assert any(event["actor"] == "a@example.com" for event in audit)
|
|
|
|
dead = client.get(f"{PREFIX}/dead-letter", headers=superuser_token_headers)
|
|
assert dead.status_code == 200
|
|
assert isinstance(dead.json(), list)
|
|
|
|
|
|
def test_the_timeseries_folds_into_the_requested_bucket(
|
|
client: TestClient, superuser_token_headers: dict[str, str], db: Session
|
|
) -> None:
|
|
"""The fold moved into SQL, so the slices still have to line up as before.
|
|
|
|
Slots are aligned to the epoch, which is what the old modulo did, and a
|
|
slice only exists where a row does.
|
|
"""
|
|
flow = "bucket-fold-test"
|
|
# The start of the current quarter hour, half an hour back so both slices
|
|
# sit inside a one hour window.
|
|
now = datetime.now(UTC).timestamp()
|
|
first = datetime.fromtimestamp(now // 900 * 900 - 1800, UTC)
|
|
for offset, executions in ((0, 1), (2, 2), (5, 4), (15, 8)):
|
|
db.add(
|
|
MetricBucket(
|
|
flow=flow,
|
|
node=f"{flow}.calc",
|
|
bucket=first + timedelta(minutes=offset),
|
|
executions=executions,
|
|
)
|
|
)
|
|
db.commit()
|
|
|
|
points = client.get(
|
|
f"{PREFIX}/timeseries",
|
|
headers=superuser_token_headers,
|
|
params={"flow": flow, "hours": 1, "bucket_s": 900},
|
|
).json()
|
|
|
|
assert len(points) == 2
|
|
assert points[0]["executions"] == 1 + 2 + 4
|
|
assert points[1]["executions"] == 8
|
|
assert points[0]["ts"] % 900 == 0
|
|
|
|
|
|
def test_the_bucket_still_filling_is_held_back(
|
|
client: TestClient, superuser_token_headers: dict[str, str], db: Session
|
|
) -> None:
|
|
"""The minute in progress is not drawn.
|
|
|
|
A bucket is upserted every flush while its minute runs, so the newest one
|
|
only ever holds part of a minute. Charted, it reads as a fall that never
|
|
happened.
|
|
"""
|
|
flow = "open-bucket-test"
|
|
minute = int(datetime.now(UTC).timestamp()) // 60 * 60
|
|
for offset, executions in ((-60, 3), (0, 1)):
|
|
db.add(
|
|
MetricBucket(
|
|
flow=flow,
|
|
node=f"{flow}.calc",
|
|
bucket=datetime.fromtimestamp(minute + offset, UTC),
|
|
executions=executions,
|
|
)
|
|
)
|
|
db.commit()
|
|
|
|
points = client.get(
|
|
f"{PREFIX}/timeseries",
|
|
headers=superuser_token_headers,
|
|
params={"flow": flow, "hours": 1},
|
|
).json()
|
|
flows = client.get(
|
|
f"{PREFIX}/flows", headers=superuser_token_headers, params={"hours": 1}
|
|
).json()
|
|
row = next(entry for entry in flows if entry["flow"] == flow)
|
|
|
|
# Unless that minute closed while the requests were in flight — then both
|
|
# buckets are complete and counting both is right.
|
|
if int(datetime.now(UTC).timestamp()) // 60 * 60 == minute:
|
|
assert [int(point["ts"]) for point in points] == [minute - 60]
|
|
# The window ends on the last closed minute, so the final slice is a
|
|
# whole one rather than however much of this minute has arrived.
|
|
assert (row["executions"], row["spark"][-1]) == (3, 3)
|
|
|
|
|
|
def test_a_zero_hour_window_is_still_an_hour(
|
|
client: TestClient, superuser_token_headers: dict[str, str]
|
|
) -> None:
|
|
"""`hours=0` divided by nothing and answered 500."""
|
|
for path in ("timeseries", "flows"):
|
|
response = client.get(
|
|
f"{PREFIX}/{path}", headers=superuser_token_headers, params={"hours": 0}
|
|
)
|
|
assert response.status_code == 200
|
|
|
|
|
|
def test_the_runs_page_carries_its_total(
|
|
client: TestClient, superuser_token_headers: dict[str, str], db: Session
|
|
) -> None:
|
|
"""A full page says how much it left behind."""
|
|
minute = datetime.now(UTC).replace(second=0, microsecond=0) - timedelta(hours=5)
|
|
for index in range(3):
|
|
db.add(
|
|
FlowRun(
|
|
id=f"paged-{index}",
|
|
flow=FLOW,
|
|
started_at=minute + timedelta(seconds=index),
|
|
status="ok",
|
|
)
|
|
)
|
|
db.commit()
|
|
|
|
body = client.get(
|
|
f"{PREFIX}/runs",
|
|
headers=superuser_token_headers,
|
|
params={
|
|
"since": minute.isoformat(),
|
|
"until": (minute + timedelta(minutes=1)).isoformat(),
|
|
"limit": 2,
|
|
},
|
|
).json()
|
|
|
|
assert len(body["data"]) == 2
|
|
assert body["count"] == 3
|
|
|
|
|
|
def test_runs_narrow_to_one_minute(
|
|
client: TestClient, superuser_token_headers: dict[str, str], db: Session
|
|
) -> None:
|
|
"""A minute picked off a chart reaches past what the recent list holds."""
|
|
minute = datetime.now(UTC).replace(second=0, microsecond=0) - timedelta(hours=3)
|
|
db.add(FlowRun(id="minute-in", flow=FLOW, started_at=minute, status="ok"))
|
|
db.add(
|
|
FlowRun(
|
|
id="minute-after",
|
|
flow=FLOW,
|
|
started_at=minute + timedelta(minutes=1),
|
|
status="ok",
|
|
)
|
|
)
|
|
db.commit()
|
|
|
|
runs = client.get(
|
|
f"{PREFIX}/runs",
|
|
headers=superuser_token_headers,
|
|
params={
|
|
"since": minute.isoformat(),
|
|
"until": (minute + timedelta(minutes=1)).isoformat(),
|
|
},
|
|
).json()
|
|
|
|
# The upper bound is exclusive, so the run starting the next minute is not
|
|
# in this one.
|
|
assert [run["id"] for run in runs["data"]] == ["minute-in"]
|
|
|
|
|
|
def test_a_running_cascade_reports_how_long_it_has_been_going(
|
|
client: TestClient, superuser_token_headers: dict[str, str], db: Session
|
|
) -> None:
|
|
"""The collector writes a duration at the end; until then, time since."""
|
|
started = datetime.now(UTC) - timedelta(seconds=30)
|
|
db.add(FlowRun(id="in-flight", flow=FLOW, started_at=started, status="running"))
|
|
db.commit()
|
|
|
|
runs = client.get(
|
|
f"{PREFIX}/runs", headers=superuser_token_headers, params={"status": "running"}
|
|
).json()
|
|
|
|
# By id rather than by position: another module can leave a run of its own
|
|
# still marked running, and the list is not this test's alone.
|
|
in_flight = next(r for r in runs["data"] if r["id"] == "in-flight")
|
|
assert in_flight["duration_ms"] >= 30_000
|
|
|
|
|
|
def test_events_narrow_to_one_minute(
|
|
client: TestClient, superuser_token_headers: dict[str, str], db: Session
|
|
) -> None:
|
|
"""The failures list reaches as far back as the charts beside it."""
|
|
minute = datetime.now(UTC).replace(second=0, microsecond=0) - timedelta(hours=4)
|
|
db.add(EngineEvent(ts=minute, type="node_error", flow=FLOW, detail="minute-in"))
|
|
db.add(
|
|
EngineEvent(
|
|
ts=minute + timedelta(minutes=1),
|
|
type="node_error",
|
|
flow=FLOW,
|
|
detail="minute-after",
|
|
)
|
|
)
|
|
db.commit()
|
|
|
|
events = client.get(
|
|
f"{PREFIX}/events",
|
|
headers=superuser_token_headers,
|
|
params={
|
|
"flow": FLOW,
|
|
"since": minute.isoformat(),
|
|
"until": (minute + timedelta(minutes=1)).isoformat(),
|
|
},
|
|
).json()
|
|
|
|
# The upper bound is exclusive, so the failure a minute later is not in it.
|
|
assert [event["detail"] for event in events] == ["minute-in"]
|
|
|
|
|
|
def test_events_narrow_to_one_run(
|
|
client: TestClient, superuser_token_headers: dict[str, str], db: Session
|
|
) -> None:
|
|
"""Reading one run's failures without filtering the engine-wide list."""
|
|
ts = datetime.now(UTC) - timedelta(hours=6)
|
|
db.add(
|
|
EngineEvent(ts=ts, type="node_error", flow=FLOW, detail="mine", run="run-mine")
|
|
)
|
|
db.add(
|
|
EngineEvent(
|
|
ts=ts, type="node_error", flow=FLOW, detail="theirs", run="run-theirs"
|
|
)
|
|
)
|
|
# What a live cascade unrelated to any run leaves, and what every row
|
|
# written before the column existed looks like.
|
|
db.add(EngineEvent(ts=ts, type="node_error", flow=FLOW, detail="neither"))
|
|
db.commit()
|
|
|
|
events = client.get(
|
|
f"{PREFIX}/events",
|
|
headers=superuser_token_headers,
|
|
params={"flow": FLOW, "run": "run-mine"},
|
|
).json()
|
|
|
|
assert [event["detail"] for event in events] == ["mine"]
|
|
|
|
|
|
def test_a_timeseries_window_can_be_named(
|
|
client: TestClient, superuser_token_headers: dict[str, str], db: Session
|
|
) -> None:
|
|
"""`since`/`until` name a span, where `hours` only measures back from now."""
|
|
base = datetime.now(UTC).replace(second=0, microsecond=0) - timedelta(hours=6)
|
|
for minute in range(4):
|
|
db.add(
|
|
MetricBucket(
|
|
flow="windowed",
|
|
node="windowed.n",
|
|
bucket=base + timedelta(minutes=minute),
|
|
executions=1,
|
|
errors=0,
|
|
messages=1,
|
|
duration_sum_ms=1.0,
|
|
duration_max_ms=1.0,
|
|
lag_sum_ms=0.0,
|
|
items=1,
|
|
)
|
|
)
|
|
db.commit()
|
|
|
|
response = client.get(
|
|
f"{PREFIX}/timeseries",
|
|
headers=superuser_token_headers,
|
|
params={
|
|
"flow": "windowed",
|
|
"since": (base + timedelta(minutes=1)).isoformat(),
|
|
"until": (base + timedelta(minutes=3)).isoformat(),
|
|
},
|
|
)
|
|
assert response.status_code == 200
|
|
# Two of the four minutes: `since` inclusive, `until` exclusive.
|
|
assert sum(point["executions"] for point in response.json()) == 2
|