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:
@@ -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.
|
||||||
|
|
||||||
|
|||||||
@@ -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)
|
||||||
|
|
||||||
|
|||||||
Reference in New Issue
Block a user