diff --git a/plugins/traefik/routes.py b/plugins/traefik/routes.py index fd746ae..3673bd6 100644 --- a/plugins/traefik/routes.py +++ b/plugins/traefik/routes.py @@ -6,6 +6,7 @@ from types import SimpleNamespace from quart import Blueprint, current_app, render_template, request from sqlalchemy import func, select, text import json +import time from steward.auth.middleware import require_role from steward.models.users import UserRole @@ -233,21 +234,28 @@ async def rows(): thresholds = current_app.config.get("THRESHOLDS", {}) scrape = current_app.config["PLUGINS"]["traefik"]["scrape_interval_seconds"] + phases = _Phases() async with current_app.db_sessionmaker() as db: # Every known router, with its most recent raw row; a router Traefik # stopped reporting gets no sparklines, so its history is not read. newest = await latest_per_router(db) current, gone = gone_routers([{"name": m.router_name, "latest": m} for m in newest], scrape) + phases.mark("latest") names = [r["name"] for r in current] history = await router_history(db, names, since, bucket_seconds(since)) + phases.mark("history") grade_routers(current, await recent_window(db, names, now), thresholds) + phases.mark("window") for r in current: points = history[r["name"]] r["sparkline_req"] = _sparkline([p.request_rate for p in points]) + r["sparkline_bytes"] = _sparkline([p.response_bytes_rate for p in points]) r["sparkline_p95"] = _sparkline([p.latency_p95_ms for p in points]) + r["sparkline_4xx"] = _sparkline([p.error_rate_4xx_pct for p in points]) r["sparkline_5xx"] = _sparkline([p.error_rate_5xx_pct for p in points]) + phases.mark("sparklines") # Latest global stat (always most recent, not range-filtered) result = await db.execute( @@ -262,6 +270,7 @@ async def rows(): select(TraefikCert).order_by(TraefikCert.not_after) ) raw_certs = result.scalars().all() + phases.mark("stats_certs") served, old = current_certs(raw_certs, scrape) domains = router_domains() @@ -284,7 +293,8 @@ async def rows(): certs = [cert_row(c) for c in served] old_certs = [cert_row(c) for c in old] problems, healthy = split_routers(current) - return await render_template( + phases.mark("cert_rows") + page = await render_template( "traefik/rows.html", problems=problems, healthy=healthy, @@ -296,6 +306,9 @@ async def rows(): old_certs=old_certs, range_key=range_key, ) + phases.mark("render") + phases.report("rows", f"routers={len(current)} range={range_key}") + return page @traefik_bp.get("/widget") @@ -310,11 +323,16 @@ async def widget(): thresholds = current_app.config.get("THRESHOLDS", {}) scrape = current_app.config["PLUGINS"]["traefik"]["scrape_interval_seconds"] + phases = _Phases() async with current_app.db_sessionmaker() as db: latest = await latest_per_router(db) + phases.mark("latest") 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) + phases.mark("window") certs = (await db.execute(select(TraefikCert))).scalars().all() + phases.mark("certs") + phases.report("widget", f"routers={len(current)}") served, _old = current_certs(certs, scrape) domains = router_domains() @@ -411,8 +429,33 @@ def _time_bucket(column, seconds: int): func.to_timestamp(0)).label("bucket") +# A rows or widget request past this logs where its time went, phase by +# phase, so a slow query names itself (#5355: 8 s on every poll, warm). +SLOW_PAGE_SECONDS = 1.0 + + +class _Phases: + """Wall-clock per phase of one request; report() logs them when slow.""" + + def __init__(self): + self.start = self.last = time.monotonic() + self.took: dict[str, float] = {} + + def mark(self, name: str) -> None: + now = time.monotonic() + self.took[name] = now - self.last + self.last = now + + def report(self, what: str, detail: str = "") -> None: + total = time.monotonic() - self.start + if total >= SLOW_PAGE_SECONDS: + current_app.logger.warning("traefik %s: slow %.1fs (%s) %s", what, total, + " ".join(f"{k}={v:.2f}s" for k, v in self.took.items()), detail) + + async def router_history(db, names: list[str], since, bucket_secs: int) -> dict[str, list]: - """{router: [rows of request_rate, latency_p95_ms, error_rate_5xx_pct]} + """{router: [rows of request_rate, latency_p95_ms, error_rate_5xx_pct, + error_rate_4xx_pct, response_bytes_rate]} per `bucket_secs` window since `since`, oldest first: one query for every router, answered from the covering (router_name, scraped_at) index (traefik_004). It was a query per router, each row a heap read, which @@ -427,6 +470,8 @@ async def router_history(db, names: list[str], since, bucket_secs: int) -> dict[ func.avg(TraefikMetric.request_rate).label("request_rate"), func.avg(TraefikMetric.latency_p95_ms).label("latency_p95_ms"), func.avg(TraefikMetric.error_rate_5xx_pct).label("error_rate_5xx_pct"), + func.avg(TraefikMetric.error_rate_4xx_pct).label("error_rate_4xx_pct"), + func.avg(TraefikMetric.response_bytes_rate).label("response_bytes_rate"), bucket_col, ) .where(TraefikMetric.router_name.in_(names)) diff --git a/plugins/traefik/templates/traefik/rows.html b/plugins/traefik/templates/traefik/rows.html index ab5bb59..377e730 100644 --- a/plugins/traefik/templates/traefik/rows.html +++ b/plugins/traefik/templates/traefik/rows.html @@ -18,7 +18,7 @@ {% macro router_card(r) %} -
+
{{ status_badge(r.state, "Failing" if r.state == 'crit' else "Warning") }}

{{ r.name }}

@@ -26,10 +26,10 @@

{{ r.why }}

- + - +
Req/s{{ "%.2f"|format(r.latest.request_rate) }}{{ r.sparkline_req|safe }}
Bandwidth{{ r.latest.response_bytes_rate|rate }}
Bandwidth{{ r.latest.response_bytes_rate|rate }}{{ r.sparkline_bytes|safe }}
p95{{ "%.0f"|format(r.latest.latency_p95_ms) }} ms{{ r.sparkline_p95|safe }}
p99{{ "%.0f"|format(r.latest.latency_p99_ms) }} ms
4xx{{ "%.1f"|format(r.latest.error_rate_4xx_pct) }}%
4xx{{ "%.1f"|format(r.latest.error_rate_4xx_pct) }}%{{ r.sparkline_4xx|safe }}
5xx{{ "%.1f"|format(r.latest.error_rate_5xx_pct) }}%{{ r.sparkline_5xx|safe }}
Last scraped {{ r.latest.scraped_at|ago }}
@@ -39,7 +39,9 @@ {% if problems or healthy or gone or certs or old_certs %} {# ── Routers that need attention ─────────────────────────────────────────── #} {% if problems %} -
+{# A grid, not CSS columns: a column box drops its last card's bottom margin, + which left the cards touching the section below (#5214). #} +
{% for r in problems %}{{ router_card(r) }}{% endfor %}
{% endif %} diff --git a/tests/plugins/traefik/test_traefik_page.py b/tests/plugins/traefik/test_traefik_page.py index be51b8a..d6dde8d 100644 --- a/tests/plugins/traefik/test_traefik_page.py +++ b/tests/plugins/traefik/test_traefik_page.py @@ -33,7 +33,7 @@ def test_router_state(latest, grade): def _router(name, latest): state, why = router_state(latest, TH) return {"name": name, "latest": latest, "state": state, "why": why, - "sparkline_req": "", "sparkline_p95": "", "sparkline_5xx": ""} + **{f"sparkline_{k}": f"" for k in ("req", "bytes", "p95", "4xx", "5xx")}} def test_failing_routers_come_before_slow_ones_and_healthy_ones_split_off(): @@ -63,6 +63,12 @@ async def test_the_page_leads_with_problems_and_folds_the_healthy(app): assert page.index(">docs") < page.index(">web") assert 'class="tone-crit">2 days' in page and 'class="tone-ok">60 days' in page assert "font-weight:600" not in page and not hex_colours(page), hex_colours(page) + # #5214: every figure that changes over time has its line, not only req/s, p95 and 5xx. + card = page[page.index(">api"):page.index('id="traefik-healthy"')] + assert [k for k in ("req", "bytes", "p95", "4xx", "5xx") if f"data-line={k}>" in card] == [ + "req", "bytes", "p95", "4xx", "5xx"] + # The cards sit in a grid with its own bottom gap, not CSS columns (whose last margin is lost). + assert '
' in page and "column-width" not in page def test_a_router_traefik_stopped_reporting_is_set_apart_not_failing():