Debuggen von GraphQL n+1 Problem mit Open Source Tracing-Tools

Einführung

Willkommen zu unserer detaillierten Untersuchung eines der häufigsten und herausforderndsten Probleme in der Welt von GraphQL: dem berüchtigten n+1-Problem. In diesem Blog-Beitrag werden wir uns mit der Natur dieses Problems befassen, wie es sich gravierend auf Produktionssoftware auswirken kann und wie wir leistungsstarke Open-Source-Tools wie OpenTelemetry, Tempo und Grafana nutzen können, um diese n+1-Probleme effektiv zu identifizieren und zu debuggen.

Das GraphQL n+1-Problem

Wenn Sie mit GraphQL arbeiten, sind Sie vielleicht schon einmal auf das n+1-Problem gestoßen. Dieses Problem tritt auf, wenn eine Anwendung n+1 Abfragen durchführt, um Daten für eine bestimmte Operation abzurufen, wobei n die Anzahl der Elemente in einer Liste ist und 1 die anfängliche Abfrage zum Abrufen der Liste darstellt. Dies führt zu einer erheblichen Anzahl von Datenbankzugriffen, was die Leistung und Effizienz Ihrer Software negativ beeinflussen kann – insbesondere in Produktionsumgebungen, in denen hohe Performance entscheidend ist.

Betrachten wir folgendes GraphQL-Schema:

1query {
2  posts {
3    id
4    title
5    author {
6      name
7    }
8  }
9}

Und wir haben die entsprechenden Resolver wie folgt:

1const resolvers = {
2  Query: {
3    posts: async () => {
4      return await PostModel.find();
5    },
6  },
7  Post: {
8    author: async (post) => {
9      return await AuthorModel.findById(post.authorId);
10    },
11  },
12};

In diesem Szenario ruft die GraphQL-Abfrage bei der Ausführung zunächst die Liste der Beiträge (Posts) ab. Anschließend ruft sie für jeden Beitrag die entsprechenden Autoreninformationen ab. Hier kommt das n+1-Problem ins Spiel. Wenn es n Beiträge gibt, gibt es n zusätzliche Abfragen, um die Autoreninformationen für jeden Beitrag zu holen. Wenn es also 100 Beiträge gibt, führen wir am Ende 101 Datenbankabfragen durch (1 anfängliche Abfrage für Beiträge + 100 Abfragen für den Autor jedes Beitrags), daher der Name „n+1-Problem“.

Je mehr Daten wir haben, desto gravierender wird dieses Problem. Dies führt zu längeren Antwortzeiten, einer höheren Belastung der Datenbank und kann im schlimmsten Fall sogar dazu führen, dass die Anwendung nicht mehr reagiert oder aufgrund von Timeouts beim Abrufen einer Datenbankverbindung (bei Verwendung von Connection Pooling) fehlschlägt.

Was ist Distributed Tracing?

Tracing ist eine leistungsstarke Technik, die Einblicke in das Verhalten Ihrer Anwendungen bietet. Sie ermöglicht es Ihnen, die Leistung zu überwachen und zu optimieren sowie Probleme wie das n+1-Problem zu erkennen und zu beheben. Tracing funktioniert, indem Anfragen verfolgt werden, während sie durch verschiedene Komponenten Ihres Systems fließen. Dies ermöglicht es uns, einen „Trace“ (eine Spur) des gesamten Pfades einer Anfrage zu sehen, was entscheidende Erkenntnisse darüber liefert, wo Zeit verbracht wird, wo Fehler auftreten und vor allem, wo Optimierungsbedarf besteht.

„Traces“ bestehen normalerweise aus mehreren „Spans“, die verschiedene Operationen wie Funktionsaufrufe, Netzwerkanfragen usw. darstellen. Jeder Span kann wiederum aus mehreren untergeordneten Spans (Child Spans) bestehen, sodass wir eine hierarchische Ansicht ähnlich einem Flame-Chart erhalten.

Moderne Tracing-Tools werden meist unter Begriffen wie „Distributed Tracing“ (verteiltes Tracing) vermarktet, was bedeutet, dass Sie eine Anfrage durch verschiedene Services hinweg verfolgen können. Dies erfordert, dass jeder Service die Span-ID des aufrufenden Services kennt, d. h. Informationen müssen zwischen den Services weitergegeben werden, was die Einrichtung von Distributed Tracing deutlich komplexer macht.

Dieselben Techniken können jedoch auch in monolithischen Anwendungen verwendet werden, oder Sie können damit beginnen, einen einzelnen Service zu instrumentieren, bevor Sie weitere Komponenten hinzufügen.

Der Tracing-Software-Stack

Um Tracing effektiv in Ihrem Stack zu nutzen, benötigen Sie mindestens drei Komponenten: Die Instrumentierungsschicht, die Tracing-Informationen in Ihrer Anwendung sammelt; das Observability-Backend, das diese Tracing-Daten sammelt, auf der Festplatte speichert und APIs zum Suchen und Inspizieren bereitstellt; und ein Visualisierungs-Tool, das manchmal im Backend enthalten ist und manchmal separat vertrieben wird.

Während zahlreiche SaaS-Lösungen im Backend- und Visualisierungsbereich verfügbar sind, konzentrieren wir uns hier auf Open-Source-Software, die selbst gehostet werden kann (self-hosted). Das gibt Ihnen die Freiheit, alles ohne Account-Registrierungen oder Gebühren zu erkunden.

Der Betrieb eines Tracing-Stacks in großem Maßstab bringt eigene Herausforderungen mit sich, aber Sie können später immer noch zu einer gehosteten Lösung wechseln, sobald Sie die Grundlagen verstanden haben.

Den Stack lokal mit docker-compose ausführen

Wir werden nun lokal einen Beispiel-Stack einrichten, indem wir OpenTelemetry zu einer bestehenden Node.js-Anwendung hinzufügen (wir gehen davon aus, dass Sie eine bestehende Anwendung haben, die Sie instrumentieren möchten) und eine Backend- sowie Visualisierungsschicht aufsetzen.

Um das lokale Testen zu erleichtern, verwenden wir docker-compose, um sowohl unsere Anwendung als auch die Tracing-Tools auszuführen. Grundkenntnisse in Docker und docker-compose sind erforderlich, um dem Folgenden zu folgen.

In diesem Beitrag verwenden wir Grafanas Tempo als Backend (ohne dessen optionale Prometheus- und Loki-Integrationen; diese werden in einem separaten Beitrag behandelt) und Grafana als Frontend.

Zu Beginn muss eine docker-compose.yml-Datei im Projektstammverzeichnis vorhanden sein, die nicht nur unsere Anwendung, sondern auch Tempo und Grafana enthält. Eine Beispieldatei (lose basierend auf den von Grafana bereitgestellten Beispielen, aber ohne Prometheus) könnte so aussehen:

1version: '2'
2services:
3    backend:
4        build:
5            context: .
6        environment:
7            NODE_ENV: development
8            TRACING_HOST: tempo
9            TRACING_PORT: '6832'
10        ports:
11            - '5000:5000'
12        links:
13            - tempo
14
15   tempo:
16      image: grafana/tempo:latest
17      command: [ "-config.file=/etc/tempo.yml" ]
18      volumes:
19        - ./tempo.yml:/etc/tempo.yml
20
21    grafana:
22        image: grafana/grafana:9.5.1
23        ports:
24            - 3000:3000
25        volumes:
26            - grafana-storage:/var/lib/grafana
27
28volumes:
29    grafana-storage:

Wir benötigen außerdem eine tempo.yml Konfigurationsdatei, um Tempo einige Einstellungen mitzugeben:

1server:
2  # This is the API port which Grafana uses to access Tempo traces
3  http_listen_port: 3200
4
5distributor:
6  receivers:
7    jaeger:
8      protocols:
9        # Enable only the thrift binary protocol which will be used by our Jaeger ingestor
10        # on port 6832
11        thrift_binary:
12
13compactor:
14  compaction:
15    block_retention: 1h                # overall Tempo trace retention. set for demo purposes
16
17storage:
18  trace:
19    backend: local                     # backend configuration to use
20    wal:
21      path: /tmp/tempo/wal             # where to store the the wal locally
22    local:
23      path: /tmp/tempo/blocks

Hinweis: Wir aktivieren hier keine persistente Speicherung von Tempo-Traces, um die lokale Festplatte nicht zu füllen. Wenn Sie Tempo neu starten, sind Ihre zuvor gesammelten Traces verschwunden.

OpenTelemetry zu Ihrer Anwendung hinzufügen

Das OpenTelemetry JavaScript SDK ist speziell für die Arbeit mit Node.js und Webanwendungen konzipiert. Es verfügt über verschiedene Module, die je nach dem zu instrumentierenden Anwendungs-Stack geladen werden können. Diese Module sind in mehrere Kategorien unterteilt:

• API-Pakete: Diese stellen die Schnittstellen und Klassen bereit, die für die Interaktion mit OpenTelemetry erforderlich sind. Sie ermöglichen die manuelle Instrumentierung und Interaktion mit Kontext, Metriken und Traces. Das Basismodul ist @opentelemetry/api.
• SDK-Pakete: Diese implementieren die APIs und sind für die Verwaltung und Sammlung von Telemetriedaten verantwortlich. Dazu gehören das Core SDK (@opentelemetry/core), das Tracing SDK (@opentelemetry/tracing), das Metrics SDK (@opentelemetry/metrics) und andere.
• Instrumentierungs-Pakete (Instrumentation Packages): Dies sind Module, die speziell für verschiedene beliebte Bibliotheken und Frameworks entwickelt wurden, wie Express (@opentelemetry/instrumentation-express), HTTP (@opentelemetry/instrumentation-http), gRPC (@opentelemetry/instrumentation-grpc) und GraphQL (@opentelemetry/instrumentation-graphql). Durch das Laden dieser Module können Sie Ihre Anwendung automatisch instrumentieren, ohne manuell Tracing-Code hinzufügen zu müssen.
• Exporter-Pakete: Exporter sind dafür verantwortlich, die Telemetriedaten an das Backend Ihrer Wahl zu senden. OpenTelemetry bietet mehrere Exporter-Pakete für beliebte Backends, darunter Jaeger (@opentelemetry/exporter-jaeger), Zipkin (@opentelemetry/exporter-zipkin) und Prometheus (@opentelemetry/exporter-prometheus).

Durch die Kombination dieser Pakete können wir unserer Anwendung recht einfach eine Instrumentierung hinzufügen, ohne uns Gedanken darüber machen zu müssen, wie wir uns in die verschiedenen Bibliotheken einklinken.

Hier ist ein Beispielcode aus der Praxis, der einfach beim Anwendungsstart geladen werden kann. Er sammelt automatisch Traces Ihrer GraphQL- und PostgreSQL-Anwendung und sendet sie über den Jaeger-Exporter an Tempo:

1import * as opentelemetry from '@opentelemetry/sdk-node';
2import { JaegerExporter } from '@opentelemetry/exporter-jaeger';
3import { Resource } from '@opentelemetry/resources';
4import { SemanticResourceAttributes } from '@opentelemetry/semantic-conventions';
5import { diag, DiagConsoleLogger, DiagLogLevel } from '@opentelemetry/api';
6import { HttpInstrumentation } from '@opentelemetry/instrumentation-http';
7import { ExpressInstrumentation } from '@opentelemetry/instrumentation-express';
8import { GraphQLInstrumentation } from '@opentelemetry/instrumentation-graphql';
9import { PgInstrumentation } from '@opentelemetry/instrumentation-pg';
10
11if (process.env['JAEGER_HOST']) {
12    // For troubleshooting, set the log level to DiagLogLevel.DEBUG
13    diag.setLogger(new DiagConsoleLogger(), DiagLogLevel.INFO);
14
15    const sdk = new opentelemetry.NodeSDK({
16        traceExporter: new JaegerExporter({
17            host: process.env['JAEGER_HOST'],
18            port: Number(process.env['JAGER_PORT']) || 6832,
19        }),
20        instrumentations: [
21            new HttpInstrumentation(),
22            new ExpressInstrumentation(),
23            new GraphQLInstrumentation({
24                mergeItems: true,
25                ignoreTrivialResolveSpans: true,
26            }),
27            new PgInstrumentation(),
28        ],
29        resource: new Resource({
30            [SemanticResourceAttributes.SERVICE_NAME]: 'backend',
31            [SemanticResourceAttributes.DEPLOYMENT_ENVIRONMENT]:
32                process.env.NODE_ENV,
33        }),
34    });
35
36    sdk.start();
37}

Natürlich müssen die importierten OpenTelemetry-Pakete mittels npm oder yarn installiert werden:

1npm i -S @opentelemetry/sdk-node @opentelemetry/exporter-jaeger @opentelemetry/instrumentation-http @opentelemetry/instrumentation-express @opentelemetry/instrumentation-graphql @opentelemetry/instrumentation-pg

Traces in Grafana ansehen

Sobald die Einrichtung abgeschlossen ist, können Sie Ihr Projekt mit docker-compose up starten. Dies sollte Ihre Anwendung sowie Tempo und Grafana starten und Grafana unter http://127.0.0.1:3000 zugänglich machen.

Grafana muss beim ersten Start konfiguriert und mit Tempo verbunden werden. Melden Sie sich zunächst mit der Standard-Kombination admin:password an.

Grafana wird Sie nun bitten, ein neues Passwort festzulegen. Merken Sie es sich gut oder notieren Sie es, da es auch nach Neustarts erhalten bleibt. Öffnen Sie als Nächstes das Seitenmenü, navigieren Sie zu „Connections -> Your connections“ und klicken Sie auf „Add data source“:

Wählen Sie aus der Liste „Distributed tracing -> Tempo“ aus und setzen Sie auf der folgenden Seite den URL-Parameter auf http://tempo:3200. Lassen Sie alle anderen Einstellungen unverändert und klicken Sie auf „Save & test“. Stellen Sie sicher, dass der Verbindungsversuch erfolgreich ist.

Sie haben Tempo nun erfolgreich mit Grafana verbunden. Öffnen Sie als Nächstes wieder das Seitenmenü und klicken Sie auf „Explore“. Oben auf dem Bildschirm sehen Sie ein Dropdown-Menü zur Auswahl der Datenquelle. Hier sollte „Tempo“ bereits vorausgewählt sein.

Führen Sie nun eine GraphQL-Anfrage an Ihr Backend aus (idealerweise diejenige, die Sie auf das n+1-Problem untersuchen möchten), um einige Tracing-Daten zu sammeln.

Wenn alles richtig konfiguriert ist, können Sie nun unter dem Auswahlfeld „Query type“ die Option „Search“ wählen und den Namen Ihres Services im Dropdown finden.

Um Ihre GraphQL-Anfrage zu untersuchen, wählen Sie „POST /graphql“ unter Span Name und klicken Sie auf den blauen Button „Run query“ oben rechts auf dem Bildschirm.

Abhängig davon, wie viele Anfragen Sie gestellt haben, sollten Sie eine Liste der gesammelten Traces finden:

Identifizierung von n+1-Problemen mithilfe von Traces

Sie können nun einen der Traces auswählen und tiefer eintauchen. Sie sehen jede Operation und alle ihre Unteroperationen als Spans, die ein- und ausgeklappt werden können. Die ersten paar Operationen werden wahrscheinlich die HTTP-Verarbeitung und potenziell Express-Middleware-Ausführungen sein. Weiter unten sehen Sie dann Ihre Resolver und schließlich die Datenbankabfragen.

Um n+1-Probleme zu identifizieren, suchen Sie nach graphql.resolve Spans, unter denen sich viele Datenbankoperationen befinden.

Dieses Beispiel stammt aus einer echten Produktionsanwendung, die wir betreiben. Hier sehen Sie, dass der Resolver mehrere Datenbankoperationen auslöst. Wenn wir die db.statement-Attribute vergleichen, sehen wir, dass sie sich nur im Parameter machine_guid unterscheiden. Das ist fast ein Lehrbuchbeispiel, das z. B. durch den Einsatz von Data Loadern oder Prefetching via JOINs vermieden werden könnte.

Wie geht es weiter?

Da dieses Tracing-Setup nun steht, kann es für weit mehr als nur das Debuggen von n+1-Problemen verwendet werden. Es kann langlaufende Datenbankabfragen, langsame HTTP-Anfragen und sogar Fehler identifizieren, die im Span mit dem Tag error=true markiert werden.

Wenn Sie dies in der Produktion ausrollen, bedenken Sie jedoch, dass das Sammeln und Speichern von Traces Kosten verursacht, sodass Sie normalerweise nur einen Teil aller Anfragen instrumentieren möchten. Dies wird als „Sampling“ bezeichnet.

Sampling ist ein kritischer Aspekt des Distributed Tracing, da es steuert, welche Traces aufgezeichnet und an Ihr Backend gesendet werden. Die drei Hauptstrategien sind „Always-On“ (alles wird aufgezeichnet), „Always-Off“ (nichts wird aufgezeichnet) und „Probability“ (Wahrscheinlichkeit), bei der ein bestimmter Prozentsatz der Traces basierend auf einer festgelegten Wahrscheinlichkeit aufgezeichnet wird. Es gibt auch „Rate Limiting“ Sampling, das die Anzahl der pro Minute aufgezeichneten Spans begrenzt.

Obwohl es ideal erscheinen mag, jeden Trace aufzuzeichnen, kann die schiere Menge an Anfragen in einer Anwendung auf Produktionsniveau überwältigend sein. Dies führt zu übermäßiger Ressourcennutzung (CPU, Speicher, Netzwerkbandbreite) und hohen Kosten für die Speicherung und Analyse dieser Daten. Darüber hinaus könnte das Sammeln jedes Traces aufgrund des zusätzlichen Overheads potenziell Latenz in Ihre Anwendung einführen. Daher muss ein Gleichgewicht gefunden werden, um eine repräsentative Stichprobe von Traces zu sammeln, die aussagekräftige Einblicke bietet, und gleichzeitig die Leistung und Kosteneffizienz Ihres Tracing-Setups zu gewährleisten.

In einem unserer nächsten Beiträge werden wir untersuchen, wie man dieses Setup mit Prometheus und Loki integriert, um ein vollständiges Bild jeder einzelnen Anfrage zu erhalten – bleiben Sie also dran.