prod-check names each trace's service and an event's fields (#387)

Two 10 s error traces named `poll` read as unexplained in a check: they
are hnopml's, a Hacker News fetch timing out, which the event's own
`error` field said all along. `traces` now prints the root service,
`trace` marks where the service changes and prints an event's fields,
and the skill's error-trace search keeps to ipx's three services.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
2026-11-06 23:44:51 +00:00
parent 1b2343cf28
commit 8a66f9c7ee
2 changed files with 21 additions and 7 deletions

View File

@@ -185,10 +185,12 @@ a count says something happened, the lines and traces say why.
R='resource.deployment.environment.name="production" && resource.service.name="ipx"' R='resource.deployment.environment.name="production" && resource.service.name="ipx"'
$Q spans "{$R && span.http.route != \"\" && span.http.route != \"/api/events\" && span.http.route !~ \"/media/.*\" && duration > 1s} | select(span.http.route)" $Q spans "{$R && span.http.route != \"\" && span.http.route != \"/api/events\" && span.http.route !~ \"/media/.*\" && duration > 1s} | select(span.http.route)"
$Q spans "{$R && name=\"step\" && duration > 500ms} | select(span.of)" $Q spans "{$R && name=\"step\" && duration > 500ms} | select(span.of)"
$Q traces '{resource.deployment.environment.name="production" && status = error}' $Q traces '{resource.deployment.environment.name="production" && resource.service.name=~"ipx|ipx-web|ipx-directory" && status = error}'
$Q trace <id> $Q trace <id>
``` ```
Tempo keeps about two weeks. A trace id from a log line that Tempo answers 404 for, or a Other services on Tower send production traces too (hnopml's `poll`, a Hacker News fetch that
times out now and then): `traces` names each trace's service and `trace` prints an event's
fields (its `error`), so say whose a failure is before reading on. Tempo keeps about two weeks. A trace id from a log line that Tempo answers 404 for, or a
search that finds only the last quarter of an hour, is Tempo not reading its stored blocks: see search that finds only the last quarter of an hour, is Tempo not reading its stored blocks: see
the monitoring section. the monitoring section.

View File

@@ -157,7 +157,8 @@ def main():
when = time.strftime("%m-%d %H:%M:%S", time.gmtime(int(t["startTimeUnixNano"]) / 1e9)) when = time.strftime("%m-%d %H:%M:%S", time.gmtime(int(t["startTimeUnixNano"]) / 1e9))
# No root name: its root span is a tap in the page, which the browser never sends. # No root name: its root span is a tap in the page, which the browser never sends.
name = t.get("rootTraceName") or "(from the page)" name = t.get("rootTraceName") or "(from the page)"
print(f"{t.get('durationMs', 0):>8}ms {when}Z {t['traceID']} {name}") # Production holds other services' traces too (hnopml's `poll`); say whose.
print(f"{t.get('durationMs', 0):>8}ms {when}Z {t['traceID']} {t.get('rootServiceName', '?')} {name}")
print(f"-- {len(traces)} trace(s)", file=sys.stderr) print(f"-- {len(traces)} trace(s)", file=sys.stderr)
elif kind == "spans": elif kind == "spans":
# The spans that matched, each with its own time: a trace's length says nothing about a # The spans that matched, each with its own time: a trace's length says nothing about a
@@ -199,7 +200,12 @@ def main():
f.write(flame_svg(stacks, n, q)) f.write(flame_svg(stacks, n, q))
print(f"-- {len(roots)} span(s) in {len(found)} trace(s): {out}, {out}.folded", file=sys.stderr) print(f"-- {len(roots)} span(s) in {len(found)} trace(s): {out}, {out}.folded", file=sys.stderr)
elif kind == "trace": elif kind == "trace":
spans = trace_spans(fetch(f"http://tempo:3200/api/traces/{q}")) tr = fetch(f"http://tempo:3200/api/traces/{q}")
spans = trace_spans(tr)
service = {sp["spanId"]: next((a["value"].get("stringValue") for a in b.get("resource", {}).get("attributes", [])
if a["key"] == "service.name"), "?")
for b in tr.get("batches", tr.get("resourceSpans", []))
for ss in b.get("scopeSpans", b.get("instrumentationLibrarySpans", [])) for sp in ss["spans"]}
kids = {} kids = {}
for sp in spans: for sp in spans:
kids.setdefault(sp.get("parentSpanId", ""), []).append(sp) kids.setdefault(sp.get("parentSpanId", ""), []).append(sp)
@@ -209,13 +215,19 @@ def main():
attrs = {a["key"]: next(iter(a["value"].values()), None) for a in sp.get("attributes", []) attrs = {a["key"]: next(iter(a["value"].values()), None) for a in sp.get("attributes", [])
if not a["key"].startswith(("code.", "thread.")) and a["key"] not in ("busy_ns", "idle_ns", "target")} if not a["key"].startswith(("code.", "thread.")) and a["key"] not in ("busy_ns", "idle_ns", "target")}
err = " ERROR" if sp.get("status", {}).get("code") in (2, "STATUS_CODE_ERROR") else "" err = " ERROR" if sp.get("status", {}).get("code") in (2, "STATUS_CODE_ERROR") else ""
print(f"{' ' * depth}{sp['name']} {ms:.0f}ms{err} {json.dumps(attrs) if attrs else ''}") parent = next((p for p in spans if p["spanId"] == sp.get("parentSpanId")), None)
# The service where it changes: a root, or a hop from ipx-web to ipx to the directory.
svc = f"[{service.get(sp['spanId'])}] " if parent is None or service.get(parent["spanId"]) != service.get(sp["spanId"]) else ""
print(f"{' ' * depth}{svc}{sp['name']} {ms:.0f}ms{err} {json.dumps(attrs) if attrs else ''}")
for e in sp.get("events", []): for e in sp.get("events", []):
msg = next((a["value"].get("stringValue") for a in e.get("attributes", []) if a["key"] == "message"), e.get("name")) fields = {a["key"]: next(iter(a["value"].values()), None) for a in e.get("attributes", [])}
msg = fields.pop("message", None) or e.get("name")
# An event's own fields carry the why: `poll failed` alone hid hnopml's timeout.
extra = {k: v for k, v in fields.items() if not k.startswith(("code.", "thread.")) and k not in ("level", "target")}
# A scan logs a skip for every feed not due; they bury what happened. # A scan logs a skip for every feed not due; they bury what happened.
if '"ev":"feed_skip"' in (msg or ""): if '"ev":"feed_skip"' in (msg or ""):
continue continue
print(f"{' ' * depth} - {msg}") print(f"{' ' * depth} - {msg}{' ' + json.dumps(extra) if extra else ''}")
for k in sorted(kids.get(sp["spanId"], []), key=lambda s: int(s["startTimeUnixNano"])): for k in sorted(kids.get(sp["spanId"], []), key=lambda s: int(s["startTimeUnixNano"])):
show(k, depth + 1) show(k, depth + 1)