Hvordan du stopper med at debugge i blinde og begynder at se dit system

Min første “rigtige” bug i produktion var en klassiker: en bruger skrev “det virker ikke” i en support-mail, og det eneste jeg havde at gå efter, var et par tilfældige console.log og en mavefornemmelse. Ingen ordentlige logs, ingen metrics, ingen måde at se hvad der faktisk var sket. Jeg gættede mig frem, deployede et fix, og håbede på det bedste.

Det viste sig at være en timeout i et eksternt API. Jeg fandt det først tre dage senere, da jeg tilfældigt så samme fejl lokalt i min terminal.

Det var dér, jeg besluttede mig for: jeg gider ikke debugge i blinde igen.

Hvis du har prøvet noget lignende, så er det her artiklen, hvor vi får styr på observability-versionen af “minimum viable product”: logs, metrics, en correlation ID og en helt tynd start på traces, som du kan få på plads på en eftermiddag.

Hvad jeg mener med observability (uden buzzwords)

Der er mange fancy definitioner af observability. Jeg bruger en simpel version:

Observability er evnen til at kunne svare hurtigt og nogenlunde sikkert på spørgsmålet: “Hvad sker der i mit system lige nu, og hvorfor?”

Til det har du tre byggesten:

• Logs – tekstlinjer om konkrete hændelser (requests, fejl, beslutninger).
• Metrics – tal over tid (antal requests, svartider, fejlrate).
• Traces – en kæde af spans, der viser vejen gennem flere services.

Du kan sagtens komme langt med de to første. Traces er gode, men du behøver ikke starte der.

Hvad du faktisk kan finde med logs, metrics og traces

Logs: “Hvad skete der med lige præcis den her request?”

Logs er til de konkrete “hvad skete der lige dér?” spørgsmål:

• Hvornår ramte brugerens request vores API?
• Hvilke parametre sendte de?
• Hvilke beslutninger tog vores kode (if/else, branches)?
• Hvilken fejl fik vi, hvis noget gik galt?

Hvis du kun har tilfældige console.log("her"), kan du ikke rekonstruere et forløb. Derfor vil vi over i structured logging om lidt.

Metrics: “Er noget ved at gå galt, eller går det allerede galt for mange?”

Metrics er til overblikket:

• Stiger fejlraten?
• Bliver svartider langsomt dårligere?
• Hvor travlt har systemet lige nu?

Metrics er gode til alarmer og dashboards. De er dårlige til “hvad skete der for bruger X kl. 14:03?”. Det er logs’ job.

Traces: “Hvordan bevæger en request sig gennem flere dele af systemet?”

Traces giver mening, når du har flere services, der kalder hinanden, eller et mix af frontend, backend og bagvedliggende jobs.

Forestil dig en request, der går:

• Frontend
• API-gateway
• Bruger-service
• Database + ekstern betalingstjeneste

Et trace kan vise dig hele kæden, hvor tid bruges, og hvor ting fejler. Det er super nyttigt, men du behøver ikke fuld OpenTelemetry-infrastruktur for at få værdi ud af logs og metrics først.

Start med logs: structured logging i stedet for tilfældige print

Hvis du kun når én ting på din “observability eftermiddag”, så lad det være structured logging.

Idéen er: hver log-linje skal være en maskinlæsbar struktur, ikke bare tekst. Typisk JSON.

Eksempel: fra kaos til struktur

Mange starter sådan her i Node:

console.log("User logged in", userId, role);
console.error("DB error", err);

Problemet er, at det er svært at søge i, svært at parse, og formatet er ikke konsistent.

Structured logging kunne se sådan ud:

console.log(JSON.stringify({
  level: "info",
  message: "user_logged_in",
  userId,
  role,
  timestamp: new Date().toISOString()
}));

console.error(JSON.stringify({
  level: "error",
  message: "db_query_failed",
  error: err.message,
  stack: err.stack,
  timestamp: new Date().toISOString()
}));

Samme info, men nu kan et værktøj (eller bare et lille script) filtrere, gruppere og tælle på tværs.

Log-levels der rent faktisk hjælper

Du behøver ikke 17 log-niveauer. Start med fire:

• debug – støj, du kun vil se lokalt eller midlertidigt i prod.
• info – normale events (request modtaget, bruger oprettet).
• warn – noget uventet, men vi kunne fortsætte.
• error – vi kunne ikke gøre det, brugeren bad om.

Et lille Node-eksempel med en håndrullet logger:

function log(level, message, extra = {}) {
  const entry = {
    level,
    message,
    timestamp: new Date().toISOString(),
    ...extra,
  };
  const line = JSON.stringify(entry);

  if (level === "error") {
    console.error(line);
  } else {
    console.log(line);
  }
}

log("info", "user_logged_in", { userId: "123", role: "admin" });

Det her er ikke fancy, men det er allerede tusind gange bedre end tilfældige print.

Hvad du bør logge ved hver request

For en typisk HTTP-request vil du som minimum logge:

• En request id (kommer vi til om lidt, når vi taler correlation ID).
• HTTP-metode og path.
• Response statuskode.
• Varighed.
• Bruger-id, hvis det findes.

Fx i Express:

app.use(async (req, res, next) => {
  const start = Date.now();

  res.on("finish", () => {
    const durationMs = Date.now() - start;
    log("info", "http_request_completed", {
      method: req.method,
      path: req.path,
      status: res.statusCode,
      durationMs,
      requestId: req.requestId, // kommer vi til
    });
  });

  next();
});

Correlation ID: sådan følger du én request gennem systemet

En ting, der ændrer din måde at debugge på, er en correlation ID (ofte bare kaldet requestId eller traceId).

Idéen er enkel: alle logs, der vedrører samme request, har det samme ID.

Hvis en bruger rapporterer en fejl, og du kan se i din frontend eller API-svar: “request-id: abc-123”, så kan du søge efter “abc-123” i dine logs og se hele historien for den ene request.

Sådan genererer og propagere du et ID

I en Node/Express-backend kan du lave en middleware, der gør to ting:

1. Hvis der allerede er en X-Request-ID header, brug den.
2. Ellers generer et nyt ID.

Eksempel:

import { randomUUID } from "crypto";

app.use((req, res, next) => {
  const incomingId = req.header("X-Request-ID");
  const requestId = incomingId || randomUUID();

  req.requestId = requestId;
  res.setHeader("X-Request-ID", requestId);

  next();
});

Når du så logger, tager du altid req.requestId med. Hvis din frontend også sender et ID med hver request, kan du forbinde hele flowet fra browser til backend.

Hvorfor correlation ID føles som snyd (på den gode måde)

Forestil dig den her bug-report: “Når jeg klikker på gem, får jeg nogle gange bare en spinner og intet sker”.

Hvis din frontend logger en fejl med requestId og måske også viser den til brugeren, kan du skrive tilbage: “Tak, kan du sende mig den request-id der står nederst i skærmen næste gang det sker?”.

Med det ID kan du søge i dine backend-logs:

cat logs.txt | jq 'select(.requestId == "abc-123")'

Nu ser du hele forløbet for lige præcis den fejlramte request i stedet for at gætte.

Metrics: 5 tal der fortæller dig om noget er galt, før nogen skriver til dig

Metrics lyder tungt, men du kan starte ekstremt småt. Mit standard-setup til en simpel webapp er:

1. Antal requests per minut.
2. Fejlrate (andel 5xx vs alle requests).
3. Latency (p95 eller p99, ikke bare gennemsnit).
4. CPU-udnyttelse.
5. Memory-usage.

Det er nok til at fange 80 % af de kedelige produktionsproblemer.

Metrics i kode: et meget lille eksempel

Du kan bruge et bibliotek som prom-client i Node til at eksponere Prometheus-metrics. Et mini-eksempel:

import client from "prom-client";

const register = new client.Registry();

const httpRequestsTotal = new client.Counter({
  name: "http_requests_total",
  help: "Total number of HTTP requests",
  labelNames: ["method", "path", "status"],
});

const httpRequestDurationMs = new client.Histogram({
  name: "http_request_duration_ms",
  help: "Duration of HTTP requests in ms",
  labelNames: ["method", "path", "status"],
  buckets: [50, 100, 200, 500, 1000, 2000],
});

register.registerMetric(httpRequestsTotal);
register.registerMetric(httpRequestDurationMs);

app.use((req, res, next) => {
  const end = httpRequestDurationMs.startTimer();

  res.on("finish", () => {
    const labels = { method: req.method, path: req.path, status: res.statusCode };
    httpRequestsTotal.inc(labels);
    end(labels);
  });

  next();
});

app.get("/metrics", async (req, res) => {
  res.set("Content-Type", register.contentType);
  res.end(await register.metrics());
});

Det ser måske lidt meget ud, men resultatet er basalt: du kan tegne grafer for antal requests og svartider per endpoint.

Hvorfor gennemsnit er en fælde

Gennemsnitlig latency kan se fin ud, mens 10 % af brugerne har en elendig oplevelse. Derfor vil du have noget ala p95/p99 (95 % eller 99 % af requests er hurtigere end den her værdi).

Mange metrics-biblioteker giver dig det automatisk ud fra histogrammer. So far, so good.

Traces med OpenTelemetry: helt ned på minimum

OpenTelemetry er stort, men du behøver ikke det hele. Tænk på det som et fælles sprog for logs, metrics og traces.

Mit råd til begyndere er ret simpelt:

• Få styr på structured logs og metrics først.
• Brug OpenTelemetry til traces, når du reelt har flere services eller komplekse flows.

Hvornår giver det mening at tænde for tracing?

Jeg plejer at sige:

• En enkelt backend-service og en database? Du kan sagtens vente.
• Flere microservices, background jobs og eksterne integrations? Så begynder traces at spare dig tid.

Hvis du vil se, hvad det kan, uden at bygge det hele, kan du lave et lille lab-projekt. På Coding Class har vi flere introartikler til backend og DevOps, der er gode at kombinere med det her emne.

En minimal OpenTelemetry-opsætning i Node

For at give en fornemmelse, ikke en fuld manual (det ville fylde en bog):

import { NodeTracerProvider } from "@opentelemetry/sdk-trace-node";
import { SimpleSpanProcessor } from "@opentelemetry/sdk-trace-base";
import { ConsoleSpanExporter } from "@opentelemetry/sdk-trace-base";
import { registerInstrumentations } from "@opentelemetry/instrumentation";
import { HttpInstrumentation } from "@opentelemetry/instrumentation-http";

const provider = new NodeTracerProvider();
provider.addSpanProcessor(new SimpleSpanProcessor(new ConsoleSpanExporter()));
provider.register();

registerInstrumentations({
  instrumentations: [
    new HttpInstrumentation(),
    // fx også Express-instrumentation
  ],
});

Det her vil allerede begynde at logge spans til console, når HTTP-requests går igennem. Ikke noget production-ready, men godt til at forstå konceptet.

Senere kan du sende traces til et rigtigt backend-system (Jaeger, Tempo, en vendor osv.). OpenTelemetrys docs er faktisk brugbare: opentelemetry.io/docs.

Alarmer: hvornår du gerne vil vækkes, og hvornår du bare vil kigge på et dashboard

En observability-fejl, jeg ser ofte, er at folk laver alarmer på alt, og så ender de med at ignorere dem alle.

Mit udgangspunkt for små projekter:

• Alarmer er til ting, der påvirker brugere her og nu.
• Dashboards er til nysgerrighed og periodiske check-ins.

Tre alarmer jeg typisk starter med

1. Fejlrate: hvis andelen af 5xx-responses er over fx 2 % i mere end 5 minutter.
2. Latency: hvis p95-svartid for dit vigtigste endpoint overstiger fx 1 sekund i 10 minutter.
3. Tilgængelighed: hvis health-check endpointet er nede i mere end 2-3 minutter.

Det kan du sætte op i stort set alle metrics-systemer. Pointen er: få, skarpe alarmer, du faktisk reagerer på.

Et konkret forløb: fra “bug report” til root cause på 15 minutter

Lad os tage en lille fiktiv (meget realistisk) historie, hvor observability-setup’et gør forskellen.

Bug-report i Slack: “Flere brugere siger, at de får fejl, når de prøver at oprette en ordre. De ser bare en generel fejlmeddelelse.”

1. Tjek metrics først

Du åbner dit dashboard og ser, at:

• Fejlrate er gået fra 0,5 % til 6 % de sidste 20 minutter.
• Det er især på POST /orders.

Så nu ved du, at det ikke bare er én bruger. Det er et rigtigt problem.

2. Find et konkret request med correlation ID

Supporteren har været venlig og kopieret en X-Request-ID fra en bruger (fordi du har lært dem det). Lad os sige den er req-abc-123.

Du hopper i dine logs og filtrerer på:

requestId = "req-abc-123" AND level = "error"

Nu ser du en log-linje:

{
  "level": "error",
  "message": "order_creation_failed",
  "requestId": "req-abc-123",
  "userId": "42",
  "errorType": "DBError",
  "errorMessage": "duplicate key value violates unique constraint "orders_pkey"",
  "timestamp": "2024-04-03T12:34:56.000Z"
}

Okay, så vi rammer en databasefejl for duplicate key.

3. Tjek flere eksempler for at bekræfte mønstret

Du søger efter alle order_creation_failed de sidste 30 minutter og ser, at det er samme fejl hver gang. Godt tegn: det er sandsynligvis samme årsag.

4. Brug logs til at se, hvad input var

Du har (selvfølgelig) bygget dine API-endpoints sådan, at du logger relevante parametre ved fejl, uden at lække persondata. Fx:

{
  "level": "error",
  "message": "order_creation_failed",
  "requestId": "req-abc-123",
  "userId": "42",
  "payloadHash": "e3b0c44298fc1c14...",
  "errorMessage": "duplicate key value violates unique constraint ..."
}

Du opdager, at det primært sker for ordre med samme payloadHash. Du kan faktisk genskabe en af dem i staging og ramme fejlen der også.

5. Root cause

Det viser sig, at din kode nogle gange prøver at oprette den samme ordre to gange hurtigt efter hinanden, fordi frontend ikke håndterer dobbeltklik på knappen. Databasen siger “nej tak, den primary key har jeg allerede”.

Fixet er relativt simpelt:

• Gør order-idempotent på backend (gentagelse giver samme resultat, ikke fejl).
• Disable knappen i frontend, mens requesten kører.

Hele forløbet tog et kvarter, fordi du havde metrics til at se, at der var et problem, og logs med correlation ID til at se hvad der skete for en konkret request.

En lille implementeringsplan: én eftermiddag og den første uge

Hvis du gerne vil i gang uden at drukne, kan du bruge det her som tjekliste.

Dag 1 (eftermiddag): få på plads nu

• Structured logging
  • Lav en lille logger-funktion, der skriver JSON med level, message, timestamp og eventuelle ekstra-felter.
  • Brug den konsekvent i stedet for console.log.
• Correlation ID
  • Tilføj middleware der sætter req.requestId og en X-Request-ID header.
  • Sørg for, at alle request-logs inkluderer requestId.
• Request-logging
  • Log mindst én linje per request med metode, path, status, duration og requestId.

Dag 2-3: metrics der giver mening

• Vælg et simpelt metrics-værktøj (Prometheus er standard, men mange hosts har noget indbygget).
• Mål:
  • Requests per minut.
  • Fejlrate (5xx).
  • Latency for dine vigtigste endpoints.
• Lav et meget simpelt dashboard med 3-4 grafer. Mere behøver du ikke i starten.

Uge 1: de små, men vigtige forbedringer

• Alarmer
  • Sæt en alarm på fejlrate.
  • Sæt en alarm på latency for et enkelt kritisk endpoint.
• Log-indsamling
  • Send logs et sted hen, hvor du kan søge (Elasticsearch, Loki, en vendor eller bare et lille log-management-værktøj).
• Mini-øvelser
  • Simulér en fejl (smid en bevidst exception) og se, om du kan finde den igen via requestId.
  • Lav en /healthz-route og log, når den bliver ramt.

Hvis du vil bygge videre herfra, er næste naturlige skridt at kigge på mere struktureret fejlhåndtering og evt. integrere med fejltracking som Sentry, især hvis du arbejder meget med frontend og JavaScript. Der er en god synergi mellem det og det, du allerede har sat op her.

Til sidst: observability er ikke et projekt, det er en vane

Det, der gør forskellen på sigt, er ikke om du bruger OpenTelemetry, Prometheus, Grafana eller noget helt fjerde. Det er, at du konsekvent skriver din kode, så den kan forklare sig selv, når den går i stykker.

Jeg synes faktisk, at måden du logger og måler på, siger mere om din modenhed som udvikler, end hvilke fancy frameworks du bruger.

Og hvis jeg skal være helt ærlig: hvis du shipper ny kode til produktion uden structured logs og en simpel fejlrate-metric, så er du ikke modig, du gambler.