Mit OpenTelemetry Tracing von der Störung zur auslösenden Anfrage

Wie OpenTelemetry Tracing mit Grafana Tempo eine Störung bis zur auslösenden Anfrage zurückverfolgt: Exemplars, Trace-to-Logs und die Grafana-Konfiguration.
Inhalt

Der Alarm meldet eine erhöhte Antwortzeit im Checkout, das Dashboard bestätigt es, und dann beginnt die Suche. Logs nach Zeitfenster filtern, Hostnamen raten, IDs kopieren. Metriken und Logs sind da, nur der Weg von der Störung zu der einen Anfrage, die sie ausgelöst hat, fehlt. Genau diesen Weg baut OpenTelemetry Tracing mit Grafana Tempo, wenn vier Verbindungsstellen richtig konfiguriert sind. Dieser Artikel zeigt die vier Stellen, die Grafana-Konfiguration dahinter und den Klickpfad, der am Ende von einem Latenzalarm bis zur Log-Zeile der Ursache führt.

Ausgangslage: Metriken und Logs laufen, der Weg zur Anfrage fehlt

Das Bild ist in den meisten Landschaften gleich, die wir übernehmen. Metriken liegen in Mimir oder Prometheus, Logs in Loki, das Alerting funktioniert. Bei einer Störung sieht der Bereitschaftsdienst den Latenzalarm, öffnet drei Dashboards und sucht in Loki mit einem Zeitfenster von zehn Minuten nach Auffälligkeiten. Die Suche endet oft bei einer plausiblen Erklärung statt bei der Ursache, weil der Beweis fehlt, dass genau diese Anfrage den Alarm ausgelöst hat.

Tracing gibt es meistens auch, aber unverbunden. Ein Teil der Dienste ist mit OpenTelemetry instrumentiert, irgendwo läuft Tempo oder ein älterer Jaeger, und die Traces lassen sich nur finden, wenn jemand eine Trace-ID kennt. Kein Log trägt die Trace-ID, keine Metrik zeigt auf einen Trace, der Service Graph ist leer.

Das Ziel, das wir in solchen Projekten festlegen, ist konkret. Von jedem Alarm aus erreicht der Bereitschaftsdienst in drei Klicks die auslösende Anfrage und ihre Log-Zeilen. Keine ID wird gesucht, keine kopiert.

Warum der Weg von der Störung zur Anfrage an vier Stellen reißt

Die Kette von der Störung zur Anfrage hat vier Verbindungsstellen, und an jeder kann sie reißen. Erstens muss die Metrik, auf der der Alarm liegt, auf einen Trace zeigen. Das leisten Exemplars, also Messpunkte in einer Metrik, die eine Trace-ID tragen. Sie entstehen im Metrics-Generator, dem Baustein von Tempo, der aus Spans Metriken berechnet.

Zweitens muss der Trace vollständig sein. Kontextweitergabe, also die Übergabe der Trace-ID von Aufruf zu Aufruf, muss über HTTP, gRPC, Messaging und Thread-Pools funktionieren. Sonst endet der Trace am Producer, und die Ursache im Consumer bleibt unsichtbar. Drittens muss der Trace überhaupt existieren. Tail-Sampling, die Auswahl der gespeicherten Traces nach vollständigem Trace, behält Fehler und langsame Anfragen komplett und verwirft den Rest anteilig.

Viertens müssen die Logs die Trace-ID tragen und ihre Labels zu den Attributen der Spans passen, sonst führt der Sprung vom Span in die Logs ins Leere. Ein häufiger Fall: Die Anwendung schreibt die ID als traceId, die Regex in Grafana sucht trace_id=, und niemand merkt es, weil Loki dafür keine Fehlermeldung liefert. Keine der vier Stellen ist ein Produktmerkmal, jede ist ein Konfigurationsdetail. Deshalb heißt „wir haben Tracing" so oft trotzdem „wir suchen".

Was OpenTelemetry Tracing mit Grafana Tempo dafür braucht

Der Datenfluss ist unspektakulär. Die Anwendungen senden Spans per OTLP an einen Collector-Agent je Node, der nach Trace-ID an ein Collector-Gateway verteilt. Dort entscheidet tail_sampling, was gespeichert wird, und der Export geht an den Tempo-Distributor. Tempo legt die Blöcke im Objektspeicher ab, und der Metrics-Generator schreibt Span-Metriken und Service-Graph-Metriken per Remote Write nach Mimir. Die Beispiele gelten für OpenTelemetry Collector Contrib 0.128, Grafana Tempo 2.8, Loki 3.5 und Grafana 12.1.

Auf der Collector-Seite sind zwei Einstellungen entscheidend. Der Propagator, die Komponente, die den Kontext in Header schreibt und liest, steht auf tracecontext,baggage, damit alle Dienste dasselbe Format sprechen. Und die Sampling-Regeln im Gateway behalten status_code: ERROR und Latenzen über einem Schwellwert vollständig. Wie diese Pipeline aussieht, beschreibt der Artikel zum Rollout über 40 Services in dieser Serie.

Auf der Tempo-Seite muss der Metrics-Generator mit den Prozessoren service-graphs und span-metrics laufen und beim Remote Write send_exemplars: true setzen. Ohne diese Zeile gibt es Metriken, aber keine Exemplars, und der erste Klick des Pfads fehlt. Mimir muss Exemplars außerdem annehmen: Das Limit max_global_exemplars_per_user steht standardmäßig auf null und muss je Mandant angehoben werden. Der Metrics-Generator ist dabei ein eigener Baustein in Tempo, dem der Distributor die Spans parallel zu den Ingestern zustellt; er bildet daraus Zähler und Histogramme und braucht dafür eigenen Speicher, den max_active_series in den Overrides begrenzt.

Die Grafana-Konfiguration, die Störung und Anfrage verbindet

Die eigentliche Verbindung entsteht in Grafana, in den Einstellungen der drei Datenquellen. Wir legen sie als Provisioning-Datei ab, damit sie versioniert ist und nicht im Klickpfad eines Administrators lebt. Der Aufbau der Schlüssel folgt der Provisioning-Dokumentation der Tempo-Datenquelle:

# Grafana 12.1, provisioning/datasources/observability.yaml, vereinfacht
apiVersion: 1
datasources:
  - name: Mimir
    type: prometheus
    uid: mimir
    url: http://mimir-query-frontend.metrics.svc:8080/prometheus
    jsonData:
      exemplarTraceIdDestinations:
        - name: traceID
          datasourceUid: tempo

  - name: Loki
    type: loki
    uid: loki
    url: http://loki-gateway.logs.svc:3100
    jsonData:
      derivedFields:
        - name: trace_id
          matcherRegex: "trace_id=(\\w+)"
          datasourceUid: tempo
          url: "$${__value.raw}"

  - name: Tempo
    type: tempo
    uid: tempo
    url: http://tempo-query-frontend.tracing.svc:3200
    jsonData:
      tracesToLogsV2:
        datasourceUid: loki
        spanStartTimeShift: "-5m"
        spanEndTimeShift: "5m"
        tags:
          - key: service.name
            value: service_name
        filterByTraceID: true
        filterBySpanID: false
      tracesToMetrics:
        datasourceUid: mimir
        spanStartTimeShift: "-5m"
        spanEndTimeShift: "5m"
        tags:
          - key: service.name
            value: service
        queries:
          - name: Fehler je Minute
            query: sum by (service) (increase(traces_spanmetrics_calls_total{$$__tags, status_code="STATUS_CODE_ERROR"}[1m]))
      serviceMap:
        datasourceUid: mimir
      nodeGraph:
        enabled: true

Die drei Blöcke tragen je eine Verbindungsstelle. exemplarTraceIdDestinations macht aus den Exemplar-Punkten in jedem Mimir-Panel Links nach Tempo; name muss das Label sein, unter dem die Exemplars die Trace-ID tragen, beim Metrics-Generator von Tempo ist das traceID. derivedFields in Loki erkennt trace_id= in der Log-Zeile und verlinkt die ID nach Tempo. tracesToLogsV2 bildet den Rückweg: Aus dem Resource-Attribut service.name des Spans wird das Loki-Label service_name, und filterByTraceID schränkt auf Zeilen mit dieser Trace-ID ein. Das Zeitfenster von fünf Minuten in beide Richtungen fängt Logs, die verzögert geschrieben wurden.

tracesToMetrics liefert von jedem Span aus die passende RED-Metrik, also Rate, Fehler und Dauer je Service; $__tags setzt Grafana aus den gemappten Attributen zu einem Label-Filter zusammen. Das doppelte Dollarzeichen ist kein Tippfehler: In Provisioning-Dateien steht $$ für ein literales $, sonst versucht Grafana, eine Umgebungsvariable einzusetzen. serviceMap und nodeGraph zeichnen aus den Service-Graph-Metriken die Abhängigkeiten der Dienste mit Fehlerraten an den Kanten. Der Dienst mit der roten Kante ist bei einer Störung der erste Verdächtige, noch bevor jemand einen Trace geöffnet hat.

Der Weg in drei Klicks, geprüft an einer echten Störung

Der Pfad beginnt bei der Alarmregel auf der Latenz aus den Span-Metriken. Die Regel liegt in Mimir auf derselben Abfrage wie das Panel, mit einem Schwellwert je Dienst, damit Alarm und Exemplar dieselbe Zeitreihe meinen. Im Expression Browser von Prometheus oder in Mimir beantwortet eine Abfrage, welcher Dienst gerade das 95. Perzentil reißt:

histogram_quantile(0.95, sum by (le, service) (increase(traces_spanmetrics_latency_bucket[1m])))

Erster Klick: Im Panel liegen die Exemplars als Punkte über der Kurve; der Punkt am Ausreißer öffnet den zugehörigen Trace in Tempo. Zweiter Klick: Im Trace ist der Span mit status = error oder der längsten Dauer markiert. Der Link „Logs for this span" führt über tracesToLogsV2 zu den Loki-Zeilen dieser Trace-ID. Dritter Klick: Die Log-Zeile nennt die Ursache, etwa den Timeout gegen die Datenbank. Von dort zurück in den Trace beantwortet TraceQL, die Abfragesprache von Tempo, ob es ein Einzelfall ist:

{ resource.service.name = "checkout-api" && status = error } >> { span.db.system = "postgresql" && duration > 2s }

Die Abfrage liefert alle fehlerhaften Checkout-Traces, in denen darunter ein Datenbank-Span länger als zwei Sekunden lief. Der Operator >> verlangt, dass der rechte Span ein Nachfahre des linken ist. Zahlen zur Zeitersparnis nennen wir nicht, weil sie von der Landschaft abhängen und sich nicht übertragen lassen. Qualitativ ist der Unterschied eindeutig: Der Bereitschaftsdienst sucht keine IDs mehr, und die Frage „Einzelfall oder Muster" ist eine Abfrage statt einer Stunde Log-Lektüre.

Wo dieser Weg an Grenzen stößt

Exemplars zeigen nur auf Traces, die es gibt. Weil der Metrics-Generator in Tempo sitzt, also hinter dem Tail-Sampling, entstehen Exemplars nur für gespeicherte Traces. Wer Span-Metriken stattdessen im Collector vor dem Sampling berechnet, bekommt Exemplars auf Traces, die nie gespeichert wurden. Der erste Klick endet dann in „Trace nicht gefunden". Die Reihenfolge der Komponenten ist hier keine Geschmacksfrage.

Der Sprung in die Logs setzt voraus, dass die Anwendung die Trace-ID überhaupt schreibt. Der OpenTelemetry Java Agent legt trace_id und span_id in den Logging-Kontext, das Logformat muss sie aber ausgeben. Bei anderen Sprachen und bei Legacy-Komponenten ohne OpenTelemetry bleibt der Rückweg leer. Und die Label-Zuordnung in tracesToLogsV2 muss zur Loki-Konfiguration passen: Heißt das Label dort app statt service_name, liefert der Link nichts, ohne einen Fehler zu zeigen.

Schließlich sind die RED-Metriken aus gesampelten Spans verschoben. Wer Fehler vollständig behält und den Rest anteilig sampelt, sieht im Service Graph Fehlerraten, die höher sind als die tatsächlichen. Für den Klickpfad ist das unerheblich, für Kapazitätsplanung nicht; dafür bleiben die Metriken aus der Anwendung selbst die richtige Quelle. Wer die Fehlerrate für ein SLO aus Span-Metriken braucht, muss den Sampling-Anteil kennen und die Zahlen entsprechend korrigieren.

Das Fazit: Der Klick von der Störung zur Anfrage ist Konfiguration

Von der Störung zur auslösenden Anfrage zu kommen, ist kein Werkzeugmerkmal, sondern das Ergebnis von vier richtig gesetzten Verbindungsstellen. Das sind Exemplars aus dem Metrics-Generator, vollständige Traces durch Kontextweitergabe, Tail-Sampling, das Fehler behält, und Logs mit Trace-ID. Die Provisioning-Datei oben ist der Teil, der in den meisten Landschaften fehlt.

Wir setzen diese vier Stellen in jedem Tracing-Rollout um und nehmen sie an einem echten Klickpfad ab, vom Alarm bis zur Log-Zeile. Wenn Sie wissen wollen, an welcher der vier Stellen Ihr Klickpfad heute reißt, ist ein Nachmittag mit Ihrer Provisioning-Datei und einem echten Alarm der schnellste Weg dorthin.

Beitrag teilen

LinkedIn
XING
E-Mail

Ein Thema aus diesem Beitrag betrifft Sie gerade?

Im Erstgespräch klären wir Ihren Stand und den nächsten sinnvollen Schritt. Mit Erfolgsgarantie auf die vereinbarten Ziele.

Erster Schritt: ein kurzes, kostenloses Erstgespräch – direkt mit einem Senior Consultant, keine Vertriebskette. Unverbindlich – danach entscheiden Sie.

// WEITERLESEN

Weitere Beiträge