fix(traefik): grade routers on their last 15 minutes; the Config tile reads Traefik's reload time (#5355)
The operator: problem cards "can disappear so quickly". Each router was graded on its latest scrape, so a 4xx share near the 1% cutoff crossed it on one scrape and fell back on the next. recent_window reads every router's last 15 minutes in one query, the error shares weighted by traffic; grade_routers uses it on the page and the dashboard widget, and the why says "over the last 15 min". traefik_config_last_reload_success is the Unix time of the last good reload, not a 0/1 flag, so the tile said "Reload failed" on every scrape. traefik_005 stores it as config_last_reload_at, and the tile reads "Config reloaded 3m ago". The router index also carries the 4xx share. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
@@ -0,0 +1,41 @@
|
||||
"""Traefik's last good config reload is a moment; routers are graded on a window
|
||||
|
||||
- traefik_config_last_reload_success is the Unix time of the last successful
|
||||
reload. It was stored as a float and read as 1.0 = success, so the page said
|
||||
"Reload failed" on every scrape (#5355). The column becomes the moment; the
|
||||
old values were timestamps misread, so they go with it.
|
||||
- Routers are now graded on their last 15 minutes (routes.recent_window),
|
||||
which reads the 4xx share too: the covering router index carries it, so
|
||||
that read stays index-only.
|
||||
|
||||
Revision ID: traefik_005_reload_at
|
||||
Revises: traefik_004_covering_indexes
|
||||
Create Date: 2026-10-08
|
||||
"""
|
||||
from typing import Sequence, Union
|
||||
from alembic import op
|
||||
import sqlalchemy as sa
|
||||
|
||||
revision: str = "traefik_005_reload_at"
|
||||
down_revision: Union[str, None] = "traefik_004_covering_indexes"
|
||||
branch_labels: Union[str, Sequence[str], None] = None
|
||||
depends_on: Union[str, Sequence[str], None] = None
|
||||
|
||||
_CHARTED = ["request_rate", "latency_p95_ms", "error_rate_5xx_pct"]
|
||||
|
||||
|
||||
def upgrade() -> None:
|
||||
op.drop_column("traefik_global_stats", "config_last_reload_success")
|
||||
op.add_column("traefik_global_stats",
|
||||
sa.Column("config_last_reload_at", sa.DateTime(timezone=True), nullable=True))
|
||||
op.drop_index("ix_traefik_metrics_router_scraped", "traefik_metrics")
|
||||
op.create_index("ix_traefik_metrics_router_scraped", "traefik_metrics", ["router_name", "scraped_at"],
|
||||
postgresql_include=_CHARTED + ["error_rate_4xx_pct"])
|
||||
|
||||
|
||||
def downgrade() -> None:
|
||||
op.drop_index("ix_traefik_metrics_router_scraped", "traefik_metrics")
|
||||
op.create_index("ix_traefik_metrics_router_scraped", "traefik_metrics", ["router_name", "scraped_at"],
|
||||
postgresql_include=_CHARTED)
|
||||
op.drop_column("traefik_global_stats", "config_last_reload_at")
|
||||
op.add_column("traefik_global_stats", sa.Column("config_last_reload_success", sa.Float, nullable=True))
|
||||
@@ -63,5 +63,7 @@ class TraefikGlobalStat(Base):
|
||||
)
|
||||
open_conns_total: Mapped[float | None] = mapped_column(Float, nullable=True)
|
||||
config_reloads_total: Mapped[float | None] = mapped_column(Float, nullable=True)
|
||||
config_last_reload_success: Mapped[float | None] = mapped_column(Float, nullable=True)
|
||||
# When Traefik last loaded its configuration successfully: its
|
||||
# traefik_config_last_reload_success gauge is that moment, not a 0/1 flag.
|
||||
config_last_reload_at: Mapped[datetime | None] = mapped_column(DateTime(timezone=True), nullable=True)
|
||||
process_memory_bytes: Mapped[float | None] = mapped_column(Float, nullable=True)
|
||||
|
||||
+68
-14
@@ -2,6 +2,7 @@
|
||||
from __future__ import annotations
|
||||
from collections import defaultdict
|
||||
from datetime import datetime, timedelta, timezone
|
||||
from types import SimpleNamespace
|
||||
from quart import Blueprint, current_app, render_template, request
|
||||
from sqlalchemy import func, select, text
|
||||
import json
|
||||
@@ -46,20 +47,71 @@ ERROR_4XX_PCT = 1.0
|
||||
_GRADE_ORDER = {"crit": 0, "warn": 1, "ok": 2}
|
||||
|
||||
|
||||
def router_state(latest, thresholds: dict) -> tuple[str, str | None]:
|
||||
"""(grade, why) for a router's latest scrape: crit while it serves 5xx,
|
||||
warn on a p95 past the latency critical cutoff (Settings → Thresholds)
|
||||
or a high 4xx share, otherwise ok with nothing to say."""
|
||||
if (latest.error_rate_5xx_pct or 0) > ERROR_5XX_PCT:
|
||||
return "crit", f"{latest.error_rate_5xx_pct:.1f}% of responses are 5xx"
|
||||
p95 = latest.latency_p95_ms
|
||||
def router_state(reading, thresholds: dict, over: str = "") -> tuple[str, str | None]:
|
||||
"""(grade, why) for a router's reading (recent_window's, or one scrape's):
|
||||
crit while it serves 5xx, warn on a p95 past the latency critical cutoff
|
||||
(Settings → Thresholds) or a high 4xx share, otherwise ok with nothing to
|
||||
say. `over` names the span the reading covers, for the why."""
|
||||
if (reading.error_rate_5xx_pct or 0) > ERROR_5XX_PCT:
|
||||
return "crit", f"{reading.error_rate_5xx_pct:.1f}% of responses are 5xx{over}"
|
||||
p95 = reading.latency_p95_ms
|
||||
if p95 is not None and status_class(p95, "latency", thresholds) == "crit":
|
||||
return "warn", f"p95 latency is {p95:.0f} ms"
|
||||
if (latest.error_rate_4xx_pct or 0) > ERROR_4XX_PCT:
|
||||
return "warn", f"{latest.error_rate_4xx_pct:.1f}% of responses are 4xx"
|
||||
return "warn", f"p95 latency is {p95:.0f} ms{over}"
|
||||
if (reading.error_rate_4xx_pct or 0) > ERROR_4XX_PCT:
|
||||
return "warn", f"{reading.error_rate_4xx_pct:.1f}% of responses are 4xx{over}"
|
||||
return "ok", None
|
||||
|
||||
|
||||
# A router is graded on its last STATE_WINDOW of traffic, not on one scrape:
|
||||
# a share near a cutoff crossed it on one scrape and fell back on the next,
|
||||
# so problem cards came and went every poll (#5214). Over the window a real
|
||||
# problem stays listed until it has been clean a while, and a one-scrape
|
||||
# blip is diluted rather than shown.
|
||||
STATE_WINDOW = timedelta(minutes=15)
|
||||
STATE_WINDOW_WORDS = " over the last 15 min"
|
||||
|
||||
|
||||
async def recent_window(db, names: list[str], now: datetime) -> dict[str, SimpleNamespace]:
|
||||
"""{router: one reading of its last STATE_WINDOW}: the 4xx and 5xx shares
|
||||
weighted by each scrape's traffic (an idle scrape's 100% counts for
|
||||
little), p95 averaged. A router with no rows in the window is absent."""
|
||||
if not names:
|
||||
return {}
|
||||
rate = TraefikMetric.request_rate
|
||||
result = await db.execute(
|
||||
select(
|
||||
TraefikMetric.router_name,
|
||||
func.sum(rate).label("req"),
|
||||
func.sum(rate * TraefikMetric.error_rate_4xx_pct).label("e4w"),
|
||||
func.sum(rate * TraefikMetric.error_rate_5xx_pct).label("e5w"),
|
||||
func.avg(TraefikMetric.error_rate_4xx_pct).label("e4"),
|
||||
func.avg(TraefikMetric.error_rate_5xx_pct).label("e5"),
|
||||
func.avg(TraefikMetric.latency_p95_ms).label("p95"),
|
||||
)
|
||||
.where(TraefikMetric.router_name.in_(names))
|
||||
.where(TraefikMetric.scraped_at >= now - STATE_WINDOW)
|
||||
.group_by(TraefikMetric.router_name)
|
||||
)
|
||||
out = {}
|
||||
for r in result.all():
|
||||
req = r.req or 0.0
|
||||
out[r.router_name] = SimpleNamespace(
|
||||
error_rate_4xx_pct=r.e4w / req if req > 0 else r.e4,
|
||||
error_rate_5xx_pct=r.e5w / req if req > 0 else r.e5,
|
||||
latency_p95_ms=r.p95,
|
||||
)
|
||||
return out
|
||||
|
||||
|
||||
def grade_routers(routers: list[dict], window: dict, thresholds: dict) -> None:
|
||||
"""Set each router's state and why from its recent window, or from its
|
||||
latest scrape when the window holds nothing."""
|
||||
for r in routers:
|
||||
reading = window.get(r["name"])
|
||||
r["state"], r["why"] = (router_state(reading, thresholds, STATE_WINDOW_WORDS) if reading
|
||||
else router_state(r["latest"], thresholds))
|
||||
|
||||
|
||||
# A router missing from this many scrapes in a row is no longer reported:
|
||||
# Traefik dropped it (a removed service), so its last state is history.
|
||||
GONE_AFTER_SCRAPES = 3
|
||||
@@ -188,10 +240,11 @@ async def rows():
|
||||
newest = await latest_per_router(db)
|
||||
current, gone = gone_routers([{"name": m.router_name, "latest": m} for m in newest], scrape)
|
||||
|
||||
history = await router_history(db, [r["name"] for r in current], since, bucket_seconds(since))
|
||||
names = [r["name"] for r in current]
|
||||
history = await router_history(db, names, since, bucket_seconds(since))
|
||||
grade_routers(current, await recent_window(db, names, now), thresholds)
|
||||
for r in current:
|
||||
points = history[r["name"]]
|
||||
r["state"], r["why"] = router_state(r["latest"], thresholds)
|
||||
r["sparkline_req"] = _sparkline([p.request_rate for p in points])
|
||||
r["sparkline_p95"] = _sparkline([p.latency_p95_ms for p in points])
|
||||
r["sparkline_5xx"] = _sparkline([p.error_rate_5xx_pct for p in points])
|
||||
@@ -259,14 +312,15 @@ async def widget():
|
||||
|
||||
async with current_app.db_sessionmaker() as db:
|
||||
latest = await latest_per_router(db)
|
||||
current, _gone = gone_routers([{"name": m.router_name, "latest": m} for m in latest], scrape)
|
||||
window = await recent_window(db, [r["name"] for r in current], now)
|
||||
certs = (await db.execute(select(TraefikCert))).scalars().all()
|
||||
|
||||
current, _gone = gone_routers([{"name": m.router_name, "latest": m} for m in latest], scrape)
|
||||
served, _old = current_certs(certs, scrape)
|
||||
domains = router_domains()
|
||||
by_router = certs_by_router([r["name"] for r in current], domains or {}, served, now)
|
||||
grade_routers(current, window, thresholds)
|
||||
for r in current:
|
||||
r["state"], r["why"] = router_state(r["latest"], thresholds)
|
||||
r["cert"] = by_router.get(r["name"])
|
||||
if r["cert"]:
|
||||
grade = status_class(r["cert"]["days"], "tls_days", thresholds)
|
||||
|
||||
@@ -152,21 +152,21 @@ def compute_router_metrics(
|
||||
def compute_global_stats(
|
||||
current: ParsedMetrics,
|
||||
previous: ParsedMetrics | None,
|
||||
) -> dict[str, float | None]:
|
||||
) -> dict[str, float | datetime | None]:
|
||||
"""Extract process-level and config health metrics from a scrape.
|
||||
|
||||
Returns:
|
||||
{
|
||||
"open_conns_total": float | None,
|
||||
"config_reloads_total": float | None,
|
||||
"config_last_reload_success": float | None, # 1.0 = success, 0.0 = failure
|
||||
"config_last_reload_at": datetime | None, # last successful reload
|
||||
"process_memory_bytes": float | None,
|
||||
}
|
||||
"""
|
||||
stats: dict[str, float | None] = {
|
||||
stats: dict[str, float | datetime | None] = {
|
||||
"open_conns_total": None,
|
||||
"config_reloads_total": None,
|
||||
"config_last_reload_success": None,
|
||||
"config_last_reload_at": None,
|
||||
"process_memory_bytes": None,
|
||||
}
|
||||
|
||||
@@ -180,11 +180,15 @@ def compute_global_stats(
|
||||
if reloads:
|
||||
stats["config_reloads_total"] = sum(reloads.values())
|
||||
|
||||
# Last reload success gauge
|
||||
# The moment of the last successful reload, as a Unix timestamp: Traefik
|
||||
# names it "last_reload_success", but it is a time, not a 0/1 flag. Read
|
||||
# as a flag, every scrape said "Reload failed" (#5355).
|
||||
last_success = current.get("traefik_config_last_reload_success", {})
|
||||
if last_success:
|
||||
# Usually a single sample with no labels
|
||||
stats["config_last_reload_success"] = next(iter(last_success.values()))
|
||||
ts = next(iter(last_success.values()))
|
||||
if ts > 0:
|
||||
stats["config_last_reload_at"] = datetime.fromtimestamp(ts, timezone.utc)
|
||||
|
||||
# Process RSS memory
|
||||
mem = current.get("process_resident_memory_bytes", {})
|
||||
|
||||
@@ -8,9 +8,8 @@
|
||||
{{ stat_tile("Needs attention", problems|length, state="crit" if problems else "inactive") }}
|
||||
{{ stat_tile("Healthy routers", healthy|length, state="up" if healthy else "inactive") }}
|
||||
{% if global_stat %}
|
||||
{% if global_stat.config_last_reload_success is not none %}
|
||||
{{ stat_tile("Config", "OK" if global_stat.config_last_reload_success == 1.0 else "Reload failed",
|
||||
state="up" if global_stat.config_last_reload_success == 1.0 else "crit",
|
||||
{% if global_stat.config_last_reload_at %}
|
||||
{{ stat_tile("Config reloaded", global_stat.config_last_reload_at|ago,
|
||||
hint=(global_stat.config_reloads_total|int ~ " reloads") if global_stat.config_reloads_total is not none else none) }}
|
||||
{% endif %}
|
||||
{% if global_stat.open_conns_total is not none %}{{ stat_tile("Open connections", global_stat.open_conns_total|int) }}{% endif %}
|
||||
|
||||
@@ -108,3 +108,34 @@ def test_router_history_reads_every_router_in_one_query_bucketed(app):
|
||||
assert got[a][0].latency_p95_ms == 20.0
|
||||
assert [r.request_rate for r in got[b]] == [4.0]
|
||||
assert got[idle] == [] # its only row is before the range
|
||||
|
||||
|
||||
def test_recent_window_weights_shares_by_traffic_and_keeps_to_the_window(app):
|
||||
"""#5214: a router is graded on its last 15 minutes. An idle scrape's
|
||||
100% 4xx counts for its trickle of traffic, not as a third of the
|
||||
average; a row older than the window is not read."""
|
||||
from plugins.traefik.models import TraefikMetric
|
||||
from plugins.traefik.routes import recent_window
|
||||
|
||||
now = datetime(2097, 3, 1, 12, 0, tzinfo=timezone.utc) + timedelta(minutes=uuid.uuid4().int % 10_000)
|
||||
tag = uuid.uuid4().hex[:8]
|
||||
busy, empty = f"busy-{tag}@docker", f"empty-{tag}@docker"
|
||||
|
||||
def row(name, ago, rate, e4, p95=10.0):
|
||||
return TraefikMetric(router_name=name, scraped_at=now - timedelta(minutes=ago), request_rate=rate,
|
||||
error_rate_4xx_pct=e4, error_rate_5xx_pct=0.0, latency_p50_ms=1.0,
|
||||
latency_p95_ms=p95, latency_p99_ms=3.0, response_bytes_rate=0.0)
|
||||
|
||||
async def go():
|
||||
async with app.db_sessionmaker() as s:
|
||||
async with s.begin():
|
||||
s.add_all([row(busy, 1, 9.9, 0.0, 10.0), row(busy, 2, 0.1, 100.0, 30.0),
|
||||
row(busy, 30, 50.0, 100.0), # outside the window
|
||||
row(empty, 30, 1.0, 100.0)])
|
||||
async with s.begin():
|
||||
return await recent_window(s, [busy, empty], now)
|
||||
|
||||
got = asyncio.run(go())
|
||||
assert set(got) == {busy} # nothing in empty's window
|
||||
assert got[busy].error_rate_4xx_pct == pytest.approx(1.0) # 0.1 × 100 over 10 req/s
|
||||
assert got[busy].latency_p95_ms == pytest.approx(20.0)
|
||||
|
||||
@@ -246,3 +246,42 @@ async def test_the_request_chart_says_its_figures_before_the_chart(app):
|
||||
assert "Requests/s (all routers)" in page and "max: 100" not in page
|
||||
assert "couldn't be drawn" in page # a failure says why in place of the chart
|
||||
assert "No Traefik requests recorded in the last 6h." in empty
|
||||
|
||||
|
||||
def test_routers_are_graded_on_their_recent_window_not_one_scrape():
|
||||
"""#5214: a 4xx share near the cutoff crossed it on one scrape and fell
|
||||
back on the next, so problem cards came and went every poll."""
|
||||
from plugins.traefik.routes import STATE_WINDOW_WORDS, grade_routers
|
||||
spiky, quiet = _latest(e4=1.5), _latest(e4=1.5)
|
||||
routers = [{"name": "spiky", "latest": spiky}, {"name": "quiet", "latest": quiet}]
|
||||
# spiky's last 15 min average well under the cutoff; quiet has no window rows.
|
||||
grade_routers(routers, {"spiky": NS(error_rate_4xx_pct=0.4, error_rate_5xx_pct=0.0, latency_p95_ms=20.0)}, TH)
|
||||
assert routers[0]["state"] == "ok"
|
||||
assert routers[1]["state"] == "warn" and not routers[1]["why"].endswith(STATE_WINDOW_WORDS)
|
||||
held = [{"name": "held", "latest": _latest()}] # clean now, bad over the window
|
||||
grade_routers(held, {"held": NS(error_rate_4xx_pct=3.0, error_rate_5xx_pct=0.0, latency_p95_ms=20.0)}, TH)
|
||||
assert held[0]["state"] == "warn"
|
||||
assert held[0]["why"] == "3.0% of responses are 4xx over the last 15 min"
|
||||
|
||||
|
||||
def test_the_last_reload_gauge_is_a_moment_not_a_flag():
|
||||
"""#5355: traefik_config_last_reload_success is a Unix time; read as a
|
||||
0/1 flag it said "Reload failed" on every scrape."""
|
||||
from plugins.traefik.scraper import compute_global_stats
|
||||
at = compute_global_stats({"traefik_config_last_reload_success": {frozenset(): 1791460000.0},
|
||||
"traefik_config_reloads_total": {frozenset(): 343.0}}, None)
|
||||
assert at["config_last_reload_at"] == datetime.fromtimestamp(1791460000.0, timezone.utc)
|
||||
assert at["config_reloads_total"] == 343.0
|
||||
never = compute_global_stats({"traefik_config_last_reload_success": {frozenset(): 0.0}}, None)
|
||||
assert never["config_last_reload_at"] is None
|
||||
|
||||
|
||||
async def test_the_config_tile_says_when_it_last_reloaded(app):
|
||||
stat = NS(config_last_reload_at=datetime.now(timezone.utc) - timedelta(minutes=3),
|
||||
config_reloads_total=343.0, open_conns_total=None, process_memory_bytes=None)
|
||||
async with app.test_request_context("/plugins/traefik/rows"):
|
||||
page = await render_plugin_template(app, "traefik", "traefik/rows.html", problems=[], healthy=[],
|
||||
gone=[], global_stat=stat, certs=[], old_certs=[], range_key="24h",
|
||||
error_4xx=1.0, error_5xx=0.1)
|
||||
assert "Config reloaded" in page and "3m ago" in page and "343 reloads" in page
|
||||
assert "Reload failed" not in page
|
||||
|
||||
Reference in New Issue
Block a user