not
e54dbe9d5d
`verify-tracing` flaked on run 722: `FAIL — no single trace spanned ['bff',
'projection-api']`, green on a plain re-run of the same commit. Not a broken trace
chain — Tempo could not ingest:
removing distributor_pool failing healthcheck addr=127.0.0.1:9095
reason="rpc error: code = DeadlineExceeded"
pusher failed to consume trace data err="context canceled" (x18)
Root cause is the mechanism of the data loss, not whatever caused the stall. Tempo
runs single-binary, so distributor and ingester are the *same process* and the
distributor's ingester pool holds exactly one, in-process, member. dskit still
health-checks it over loopback gRPC with a 1s deadline; on the shared runner a
transient stall blows that, the only ingester is dropped from the pool, and every
push fails until the next 15s check interval — spans silently lost. With one
in-process ingester the check can never route around a failure, so it can only ever
discard data.
Fix: `ingester_client.pool_config.healthcheckenabled: false`. This addresses both
candidate triggers (GC pressure near `mem_limit`, CPU contention) at the point where
they turn into lost data, so `mem_limit: 400m` stays untouched — raising it would
risk reintroducing the verify-e2e OOM of #144 on a memory-tight runner.
Also print `tempo_distributor_ingester_clients` on the check's failure path: a
recurrence then names Tempo-dropped-spans instead of costing another container-log
dive, since from the check's side that is indistinguishable from missing
instrumentation.
Verified against the built image: config parses (`-config.verify`), the effective
`/status/config` reports `healthcheckenabled: false`, and the diagnostic reads the
metric off a live Tempo.
97 lines
3.3 KiB
Python
Executable File
97 lines
3.3 KiB
Python
Executable File
#!/usr/bin/env python3
|
|
"""S-16b (#123): prove distributed tracing works end to end.
|
|
|
|
Generate anonymous BFF traffic (GET /openbaar/register, which the BFF serves by
|
|
calling projection-api — no auth, no OpenZaak egress), then query Tempo and assert
|
|
that ONE trace contains spans from both `bff` and `projection-api`. That proves the
|
|
services export OTLP to Tempo AND that the W3C traceparent propagates across the
|
|
HttpClient hop, stitching the request into a single connected trace.
|
|
|
|
Stdlib only (urllib/json) so it runs in a bare python:3-slim container in-network.
|
|
"""
|
|
import json
|
|
import os
|
|
import sys
|
|
import time
|
|
import urllib.error
|
|
import urllib.parse
|
|
import urllib.request
|
|
|
|
BFF = os.environ["BFF"] # http://<bff-ip>:8080
|
|
TEMPO = os.environ["TEMPO"] # http://<tempo-ip>:3200
|
|
TIMEOUT = int(os.environ.get("TRACING_TIMEOUT", "90"))
|
|
WANT = {"bff", "projection-api"} # the two services that must share one trace
|
|
|
|
|
|
def _get(url):
|
|
with urllib.request.urlopen(url, timeout=10) as r:
|
|
return r.read()
|
|
|
|
|
|
def generate_traffic():
|
|
# A non-2xx still produces spans; only total unreachability of the BFF is fatal.
|
|
for _ in range(3):
|
|
try:
|
|
_get(f"{BFF}/openbaar/register")
|
|
except urllib.error.HTTPError:
|
|
pass
|
|
|
|
|
|
def search_trace_ids():
|
|
q = urllib.parse.quote('{ resource.service.name = "bff" }')
|
|
try:
|
|
data = json.loads(_get(f"{TEMPO}/api/search?q={q}&limit=50"))
|
|
except Exception:
|
|
return []
|
|
return [t["traceID"] for t in data.get("traces", [])]
|
|
|
|
|
|
def services_in_trace(trace_id):
|
|
try:
|
|
data = json.loads(_get(f"{TEMPO}/api/traces/{trace_id}"))
|
|
except Exception:
|
|
return set()
|
|
names = set()
|
|
for batch in data.get("batches", []):
|
|
for attr in batch.get("resource", {}).get("attributes", []):
|
|
if attr.get("key") == "service.name":
|
|
names.add(attr.get("value", {}).get("stringValue"))
|
|
return names
|
|
|
|
|
|
def tempo_ingest_state():
|
|
"""#156: distinguish a broken trace chain from Tempo dropping spans. `ingester_clients` is 0
|
|
when the distributor has evicted its (single, in-process) ingester over a failed loopback
|
|
health check — pushes fail and spans are lost, which looks identical to missing instrumentation
|
|
from here. Diagnostics only; never fails the check."""
|
|
try:
|
|
for line in _get(f"{TEMPO}/metrics").decode().splitlines():
|
|
if line.startswith("tempo_distributor_ingester_clients "):
|
|
return f"tempo {line.strip()} (0 = no ingester in the pool — evicted, so pushes\n are failing and spans are being dropped; see #156)"
|
|
except Exception as e:
|
|
return f"tempo /metrics unreadable: {e}"
|
|
return "tempo_distributor_ingester_clients not reported"
|
|
|
|
|
|
def main():
|
|
deadline = time.time() + TIMEOUT
|
|
generate_traffic()
|
|
seen = set()
|
|
while time.time() < deadline:
|
|
for tid in search_trace_ids():
|
|
names = services_in_trace(tid)
|
|
seen |= names
|
|
if WANT.issubset(names):
|
|
print(f"OK — trace {tid} spans {sorted(names)}")
|
|
return 0
|
|
time.sleep(3)
|
|
generate_traffic()
|
|
print(f"FAIL — no single trace spanned {sorted(WANT)}; services seen: {sorted(seen)}",
|
|
file=sys.stderr)
|
|
print(f" {tempo_ingest_state()}", file=sys.stderr)
|
|
return 1
|
|
|
|
|
|
if __name__ == "__main__":
|
|
sys.exit(main())
|