Bootcamp i FastAPI-backendudvikling · Lektion

Struktureret JSON-logging og korrelations-id'er

Udsend strukturerede logs med request-scopede korrelations-id'er, der bevares på tværs af asynkrone grænser og tjenester.

Lektion 1 af 413 trin

Struktureret JSON-logging og korrelations-id'er er en gratis Bootcamp i FastAPI-backendudvikling-lektion på CoddyKit. Dette er lektion 1 af 4. Du kan læse alle 3 lektioner i dette læringsspor gratis i deres fulde længde — derefter låser CoddyKit PRO alle lektioner op samt praktiske øvelser med en indbygget kodeeditor og en AI-underviser døgnet rundt. Den er en del af læringsforløbet i Bootcamp i FastAPI-backendudvikling, og dine fremskridt synkroniseres på tværs af nettet og CoddyKit-appen. Bootcamp i FastAPI-backendudvikling-kurset indeholder 4 lektioner i alt.

Hvorfor strukturerede logge

I produktion er logge data, ikke prosa. En linje som User 42 failed login from 10.0.0.3 er let at forstå for et menneske, men besværlig for maskiner: Du kan ikke pålideligt filtrere, aggregere eller oprette alarmer ud fra den.

Struktureret logning udsender hver hændelse som et JSON-objekt med stabile felter, der kan forespørges på:

timestamp, level, message
request_id / correlation_id
kontekst som user_id, path, status_code, duration_ms

Logaggregatorer (Loki, Elasticsearch, Datadog) indekserer derefter disse felter, så du kan køre forespørgsler som level=ERROR AND path=/checkout.

En JSON-log på én linje

Den enkleste strukturerede log er blot en dict, der serialiseres til JSON på én linje. Ét JSON-objekt pr. linje er formatet JSON Lines (NDJSON), som stort set alle logafsendere forstår.

Dette selvstændige eksempel viser den struktur, vi sigter efter. Bemærk, at felterne er flade og navngivet konsekvent.

import json
import time

def log(level, message, **fields):
    record = {
        "timestamp": time.strftime("%Y-%m-%dT%H:%M:%SZ", time.gmtime()),
        "level": level,
        "message": message,
        **fields,
    }
    print(json.dumps(record))

log("INFO", "request completed", path="/checkout", status_code=200, duration_ms=42)
log("ERROR", "db timeout", path="/orders", correlation_id="abc-123")

En tilpasset JSON-formaterer

Hvis du selv skriver print(json.dumps(...)), omgår du Pythons logging-modul og mister niveauer, håndteringer og logge fra biblioteker. Tilslut i stedet en JSON-formaterer til den almindelige logging-stak.

En formaterers opgave er at omdanne en LogRecord til en streng. Her returnerer vi JSON. record.__dict__ indeholder alle extra={...}-felter, som du angiver på kaldsstedet.

import json
import logging

class JsonFormatter(logging.Formatter):
    def format(self, record):
        payload = {
            "level": record.levelname,
            "logger": record.name,
            "message": record.getMessage(),
        }
        if record.exc_info:
            payload["exc"] = self.formatException(record.exc_info)
        return json.dumps(payload)

handler = logging.StreamHandler()
handler.setFormatter(JsonFormatter())
logging.basicConfig(level=logging.INFO, handlers=[handler])

logging.getLogger("app").info("service started", extra={"port": 8000})

Problemet med korrelations-id'er

En enkelt brugerforespørgsel forgrener sig ofte: API-håndtering -> servicelag -> databasekald -> udgående HTTP-kald til en anden tjeneste. Hvis hver loglinje er anonym, kan du ikke sætte dem sammen til én samlet fortælling.

Et korrelations-id (også kaldet et forespørgsels-id eller sporings-id) er en unik værdi, der genereres én gang pr. indgående forespørgsel og knyttes til hver loglinje, der produceres under håndteringen af den. Derefter henter correlation_id=abc-123 hele tidslinjen på tværs af funktioner og endda på tværs af tjenester.

Udfordringen er: Hvordan gør du dette id tilgængeligt dybt nede i kaldestakken uden at føre det gennem hvert funktionsargument?

ContextVar: Tilstand afgrænset til forespørgslen

Det rene svar er contextvars.ContextVar. I modsætning til en global variabel indeholder en ContextVar en værdi, der er isoleret pr. logisk udførelseskontekst og, afgørende nok, videresendes korrekt på tværs af async-afventninger.

Hver samtidige forespørgsel kører i sin egen kontekst, så indstilling af korrelations-id'et i én forespørgsel lækker aldrig over i en anden, selv når mange forespørgsler udføres indflettet på den samme hændelsesløkke.

import asyncio
from contextvars import ContextVar

correlation_id: ContextVar[str] = ContextVar("correlation_id", default="-")

async def handle(name, cid):
    correlation_id.set(cid)
    await asyncio.sleep(0.01)
    # value survives the await and stays isolated per task
    print(name, "->", correlation_id.get())

async def main():
    await asyncio.gather(
        handle("req-A", "aaa"),
        handle("req-B", "bbb"),
    )

asyncio.run(main())

Indsættelse af id'et via et logfilter

Hvis korrelations-id'et automatisk skal med på hver loglinje, skal du tilknytte et logging.Filter, der læser ContextVar og kopierer værdien til posten. Et filter kører for hver post, der passerer gennem håndteringen, så intet kaldssted behøver at huske at sende id'et med.

Formatereren læser derefter record.correlation_id på samme måde som ethvert andet felt.

import json
import logging
from contextvars import ContextVar

correlation_id: ContextVar[str] = ContextVar("correlation_id", default="-")

class CorrelationFilter(logging.Filter):
    def filter(self, record):
        record.correlation_id = correlation_id.get()
        return True

class JsonFormatter(logging.Formatter):
    def format(self, record):
        return json.dumps({
            "level": record.levelname,
            "message": record.getMessage(),
            "correlation_id": getattr(record, "correlation_id", "-"),
        })

h = logging.StreamHandler()
h.addFilter(CorrelationFilter())
h.setFormatter(JsonFormatter())
logging.basicConfig(level=logging.INFO, handlers=[h])

correlation_id.set("abc-123")
logging.getLogger("app").info("order placed")

FastAPI-middleware til indstilling af id'et

I FastAPI er det rigtige sted at etablere korrelations-id'et en HTTP-middleware, som omslutter hver forespørgsel. Mønstret er:

Læs en indgående X-Request-ID- eller X-Correlation-ID-header, hvis en kalder (gateway eller opstrøms tjeneste) allerede har angivet en.
Generér ellers en ny UUID.
Gem den i ContextVar, så alle efterfølgende logge tager den med.
Send den tilbage i svarheaderen, så klienter kan oplyse den i fejlrapporter.

Dette er framework-kode, der kræver en kørende server, så den er illustrativ snarere end kørbar.

import uuid
from fastapi import FastAPI, Request
from contextvars import ContextVar

correlation_id: ContextVar[str] = ContextVar("correlation_id", default="-")
app = FastAPI()

@app.middleware("http")
async def correlation_middleware(request: Request, call_next):
    cid = request.headers.get("X-Request-ID") or str(uuid.uuid4())
    token = correlation_id.set(cid)
    try:
        response = await call_next(request)
    finally:
        correlation_id.reset(token)
    response.headers["X-Request-ID"] = cid
    return response

Hvorfor reset() med et Token er vigtigt

Bemærk token = correlation_id.set(cid) efterfulgt af correlation_id.reset(token) i en finally-blok. Tokenet gendanner den tidligere værdi, når anmodningen afsluttes.

Under en ASGI-server kan arbejderopgaver og kontekster genbruges. Nulstilling forhindrer, at et forældet ID fra en afsluttet anmodning flyder ind i en senere anmodning, der har glemt at sætte sit eget. Sæt altid set() sammen med reset() i middleware, og gør det i finally, så det også køres, når handleren kaster en fejl.

from contextvars import ContextVar

cv: ContextVar[str] = ContextVar("cv", default="-")

print(cv.get())          # -
token = cv.set("req-1")
print(cv.get())          # req-1
cv.reset(token)
print(cv.get())          # back to -

Baggrundsopgaver og tråde, der fortsætter

ContextVar viderefører automatisk sin værdi på tværs af await inden for den samme opgave, men en værdi følger ikke automatisk med arbejde, du sender til en anden tråd (for eksempel run_in_executor eller blokerende database-drivere).

Hvis du vil føre konteksten med over en trådgrænse, skal du gemme den med contextvars.copy_context() og køre den kaldte funktion inde i den kopi. asyncio gør allerede dette for create_task; for rå eksekveringsprogrammer skal du selv gøre det manuelt.

import contextvars
from concurrent.futures import ThreadPoolExecutor

cid = contextvars.ContextVar("cid", default="-")

def work():
    return cid.get()

cid.set("trace-9")
ctx = contextvars.copy_context()
with ThreadPoolExecutor() as pool:
    # ctx.run carries the ContextVar value into the worker thread
    result = pool.submit(ctx.run, work).result()

print("in thread:", result)  # trace-9

Videreførelse på tværs af tjenester

Et korrelations-ID er kun nyttigt fra ende til anden, hvis det krydser tjenestegrænser. Når din FastAPI-tjeneste kalder en anden tjeneste, skal du videresende ID'et som en HTTP-header, så loggene længere nede i kæden deler den samme værdi.

Læs det fra ContextVar, og indsæt det i hvert udgående klientkald. Den modtagende tjenestes middleware læser denne header i stedet for at generere et nyt ID, så ét ID dækker hele kaldkæden.

import httpx
from contextvars import ContextVar

correlation_id: ContextVar[str] = ContextVar("correlation_id", default="-")

async def call_downstream(url: str):
    headers = {"X-Request-ID": correlation_id.get()}
    async with httpx.AsyncClient() as client:
        resp = await client.get(url, headers=headers)
        return resp.json()

Sådan samler du det hele med structlog

I stedet for selv at opbygge formaterere bruger mange team structlog, som sammensætter en behandlingspipeline af processorer og gengiver JSON til sidst. En processor kan hente korrelations-ID'et fra ContextVar og automatisk føje det til hver hændelse.

Fordelene forstærker hinanden: ensartet JSON-output, nem binding af kontekst pr. hændelse via logger.bind(...) og en ren integration med standardbibliotekets modul logging, så bibliotekernes logge også bliver opsamlet.

import structlog
from contextvars import ContextVar

correlation_id: ContextVar[str] = ContextVar("correlation_id", default="-")

def add_correlation_id(logger, method_name, event_dict):
    event_dict["correlation_id"] = correlation_id.get()
    return event_dict

structlog.configure(
    processors=[
        add_correlation_id,
        structlog.processors.add_log_level,
        structlog.processors.TimeStamper(fmt="iso"),
        structlog.processors.JSONRenderer(),
    ]
)

correlation_id.set("abc-123")
log = structlog.get_logger()
log.info("checkout_completed", amount=49.9, currency="EUR")

Hurtig kontrol

Test din forståelse af, hvordan korrelations-ID'er videreføres i asynkrone FastAPI-tjenester.

Besvar den i den interaktive lektion

Opsummering

Du har opbygget struktureret logning for FastAPI, der er afgrænset til den enkelte anmodning:

Strukturerede JSON-logge via en tilpasset logging.Formatter (eller structlog) gør loggene søgbare.
Korrelations-ID'er binder hver loglinje fra én anmodning sammen på tværs af funktioner og tjenester.
contextvars.ContextVar indeholder ID'et med isolation pr. anmodning og overlever await-grænser.
Et logningsfilter føjer ID'et til hver post, så intet kaldested behøver at huske det.
FastAPI-middleware læser X-Request-ID eller genererer et UUID og parrer derefter set() med reset(token) i finally.
Før konteksten med ind i tråde via copy_context() og på tværs af tjenester ved at videresende ID-headeren.

Resultatet er, at ét ID, som du søger efter i din logaggregator, viser hele forløbet for enhver anmodning.

Gratis at komme i gang

Lær Bootcamp i FastAPI-backendudvikling med en AI-underviser — gratis

Skriv og kør rigtig kode i din browser, få øjeblikkelig hjælp fra en AI-underviser døgnet rundt, og fortsæt, hvor du slap, på web eller i appen.

Kurser: 21
Lektioner: 84

Start gratis Se hele kurset

Ofte stillede spørgsmål

Er lektionen “Struktureret JSON-logging og korrelations-id'er” gratis?

Ja — alle 3 lektioner i læringssporet Bootcamp i FastAPI-backendudvikling, inklusive “Struktureret JSON-logging og korrelations-id'er”, kan læses gratis i deres fulde længde her på webstedet. Derefter låser CoddyKit PRO alle lektioner op samt interaktive øvelser med en indbygget kodeeditor og en AI-underviser døgnet rundt. Bootcamp i FastAPI-backendudvikling-kurset indeholder 4 lektioner i alt.

Hvad lærer jeg i “Struktureret JSON-logging og korrelations-id'er”?

Udsend strukturerede logs med request-scopede korrelations-id'er, der bevares på tværs af asynkrone grænser og tjenester. Du øver dig i Bootcamp i FastAPI-backendudvikling med praktisk kode, som du kører direkte i browseren, og en AI-vejleder døgnet rundt besvarer dine spørgsmål, mens du arbejder dig gennem lektionen.

Skal jeg have erfaring for at begynde på Bootcamp i FastAPI-backendudvikling?

Der kræves ingen tidligere erfaring. Bootcamp i FastAPI-backendudvikling på CoddyKit er tilrettelagt for både begyndere og øvede, så du kan starte her eller fra begyndelsen og lære i dit eget tempo. Dette er lektion 1 af 4.

Hvor lang tid tager lektionen “Struktureret JSON-logging og korrelations-id'er”?

De fleste CoddyKit-lektioner tager cirka 5–10 minutter. Hver lektion er kort og interaktiv, så du gør løbende fremskridt og kan fortsætte, hvor du slap – på både web og app.

Kan jeg skrive og køre kode i denne Bootcamp i FastAPI-backendudvikling-lektion?

Ja. Alle Bootcamp i FastAPI-backendudvikling-lektioner har en indbygget kodeeditor, så du kan skrive og køre rigtig kode direkte i din browser og få øjeblikkelig feedback fra AI – uden lokal opsætning.

Alle lektioner i dette kursus

Struktureret JSON-logging og korrelations-id'er
Distribueret tracing med OpenTelemetry
Prometheus-metrics og RED/USE-dashboards
Alarmering på SLO'er og error budgets

← Tilbage til Bootcamp i FastAPI-backendudvikling