Logging & observabilité

TL;DR — Logs, metrics, traces : les trois piliers d'observabilité, qui répondent à des questions différentes. Logs = "que s'est-il passé ici ?". Metrics = "comment ça va globalement ?". Traces = "où est passée cette requête ?". Nest a un Logger basique ; en prod tu passes à pino (10–100x plus rapide) + OpenTelemetry pour le reste. La discipline ninja : un seul correlationId qui traverse logs + traces, propagé via AsyncLocalStorage.

🧠 Mental model — ASCII diagram + analogy

   ┌─────────── Request ────────────┐
   │                                │
   ▼                                ▼
[ Middleware ]────► AsyncLocalStorage ◄───[ Service ]
   │  set traceId/spanId/userId            │  reads context
   │                                       │  → logger.info({...ctx})
   ▼                                       ▼
[ HTTP log ]                          [ Domain log ]
   │                                       │
   └──► Loki / ELK ◄──────────────────────┘
              ▲
              │ correlate by traceId
              │
   ┌──────────┴──────────┐
   │   OpenTelemetry     │ ─► Tempo / Jaeger (traces)
   │   /metrics endpoint │ ─► Prometheus / VictoriaMetrics
   └─────────────────────┘

Analogie : un log est une photo (qu'est-ce qui s'est passé à ce moment). Une trace est un film (la séquence complète). Une metric est un thermomètre (état agrégé). Tu as besoin des trois — mais sans correlationId/traceId partagé, c'est trois écrans de surveillance qui ne se parlent pas.

Important : JSON structuré obligatoire dès staging. Les logs string non parsables sont inutiles dans Loki/Elastic. Un log doit être interrogeable : level, time, traceId, userId, event, latencyMs, etc.

🛠️ Code minimal

Pino comme logger Nest

// main.ts
import { LoggerModule } from 'nestjs-pino';

@Module({
  imports: [
    LoggerModule.forRoot({
      pinoHttp: {
        level: process.env.LOG_LEVEL ?? 'info',
        transport: process.env.NODE_ENV !== 'production'
          ? { target: 'pino-pretty' }
          : undefined,
        redact: ['req.headers.authorization', 'req.headers.cookie', '*.password'],
        customProps: (req) => ({ traceId: req.headers['x-trace-id'] }),
        serializers: {
          req: (req) => ({ id: req.id, method: req.method, url: req.url }),
        },
      },
    }),
  ],
})
export class AppModule {}

// main bootstrap
const app = await NestFactory.create(AppModule, { bufferLogs: true });
app.useLogger(app.get(Logger));

Correlation ID via AsyncLocalStorage

// als/context.service.ts
import { AsyncLocalStorage } from 'node:async_hooks';

type Ctx = { traceId: string; userId?: string };
export const als = new AsyncLocalStorage<Ctx>();

@Injectable()
export class ContextService {
  get(): Ctx | undefined { return als.getStore(); }
  set<T>(ctx: Ctx, fn: () => T): T { return als.run(ctx, fn); }
}

// als/correlation.middleware.ts
@Injectable()
export class CorrelationMiddleware implements NestMiddleware {
  use(req: Request, res: Response, next: NextFunction) {
    const traceId = (req.headers['x-trace-id'] as string) ?? randomUUID();
    res.setHeader('x-trace-id', traceId);
    als.run({ traceId }, () => next());
  }
}

Dans un service quelconque :

this.logger.log({ event: 'order.created', orderId, traceId: this.ctx.get()?.traceId });

OpenTelemetry — traces + metrics

// otel.ts (require AVANT le bootstrap Nest)
import { NodeSDK } from '@opentelemetry/sdk-node';
import { getNodeAutoInstrumentations } from '@opentelemetry/auto-instrumentations-node';
import { OTLPTraceExporter } from '@opentelemetry/exporter-trace-otlp-http';
import { PrometheusExporter } from '@opentelemetry/exporter-prometheus';

const sdk = new NodeSDK({
  traceExporter: new OTLPTraceExporter({ url: process.env.OTEL_EXPORTER_OTLP_ENDPOINT }),
  metricReader: new PrometheusExporter({ port: 9464 }),
  instrumentations: [getNodeAutoInstrumentations({
    '@opentelemetry/instrumentation-fs': { enabled: false }, // bruit
  })],
  serviceName: 'orders-api',
});
sdk.start();

Démarre avec node -r ./otel.js dist/main.js. Les instrumentations auto patchent Express, Fastify, pg, ioredis, http, etc.

Custom metric

import { metrics } from '@opentelemetry/api';
const meter = metrics.getMeter('orders');
const orderCounter = meter.createCounter('orders_created_total', { description: 'Orders created' });

@Injectable()
export class OrdersService {
  async create(dto: CreateOrderDto) {
    /* ... */
    orderCounter.add(1, { customerType: customer.type });
  }
}

🎯 Patterns courants

1. Three-pillar correlation — traceId injecté par middleware, propagé via ALS, ajouté à chaque log et chaque span. Un seul ID pour basculer log → trace dans Grafana.
2. Log level par module — pino.child({ module: 'OrdersService' }). Tu peux taper level=debug uniquement sur le module qui débugge.
3. Sampling de traces — parentbased_traceidratio à 0.1 (10%) en prod, 1.0 en staging. Sinon Tempo/Jaeger explose en coût.
4. RED metrics par endpoint (Rate, Errors, Duration) — déjà capturés par auto-instrumentations via http.server.duration. Dashboard Grafana standard.
5. USE metrics côté infra (Utilization, Saturation, Errors) — CPU, mem, event loop lag (@opentelemetry/instrumentation-runtime-node).
6. Log sampling sur les hot paths — 1 log/1000 requêtes pour les health checks, full pour les erreurs. Évite de saturer Loki.

🔄 Versions — Nest 7 / 8 / 9 / 10 / 11

• 7 : Logger Nest basique. Pas de support natif pino. nest-winston populaire.
• 8 : Logger peut être surchargé via useLogger(false) ou instance custom. LoggerService interface stabilisée.
• 9 : bufferLogs: true ajouté à NestFactory.create — bufferise jusqu'à app.useLogger(...). Avant, les logs de boot étaient perdus avec ton logger custom.
• 10 : auto-instrumentation OpenTelemetry compatible. nestjs-pino v4. Drop Node 14.
• 11 : Logger accepte un objet en plus du message string (logger.log({ event, data })). Avant, fallait JSON.stringify manuellement. Compatible OTel 1.x.

OTel side : la spec a fait 1.0 mid-2023, les SDK Node sont stables depuis. Avant ça, breaking changes fréquents — vérifie la version exporter ↔ SDK.

Sampling vs head-based vs tail-based

Pour les traces :

• Head-based sampling — décision au premier span (avant de connaître l'issue). Léger, mais peut rater des traces intéressantes.
• Tail-based sampling — collector buffer toute la trace, décide après (ex. garde les 100% des traces avec erreur, 10% des autres). Plus cher (Collector OTel mémoire/CPU), bien plus utile pour le debug.

Pour Grafana Tempo : configure le collector OTel en tail_sampling mode. Pour Honeycomb / Datadog : c'est nativement supporté.

Pour les logs : sampling moins courant, mais légitime sur des access logs très volumineux (10–100 millions/jour).

⚠️ Pitfalls

1. Console.log en prod — ralentit (sync stdout buffering), pas structuré, pas redacté. Bannir au linter (no-console: error).
2. PII dans les logs — emails, tokens, CB. RGPD friendly = redact. pino redact: ['*.password', 'req.body.creditCard'].
3. ALS et workers — worker_threads ne propagent pas ALS. Si tu offload du calcul, passe explicitement traceId en message.
4. Stringification d'erreurs — console.log(err) → {}. Pino la sérialise correctement via err serializer. Ou utilise errorAsObject(err).
5. OTel + Express middleware order — l'instrumentation doit charger avant require('express'). Sinon les routes ne sont pas instrumentées. node -r ./otel.js est la garantie.
6. Trop de cardinality dans les metrics — userId en label = explosion Prometheus (millions de séries). Limite à des dimensions stables (route, status_code, method).
7. Niveaux mal choisis — error pour une 404 client est du bruit. Réserve error aux 5xx + exceptions inattendues. 4xx = warn ou info.
8. Health checks loggés — /health toutes les 5s par K8s = 17k logs/jour. Skip middleware ou filtre par path.

🧪 Testing (when relevant)

• Tests d'intégration : injecter un fake logger pour vérifier qu'un event est loggé.

const logSpy = jest.spyOn(Logger.prototype, 'log');
await service.create(dto);
expect(logSpy).toHaveBeenCalledWith(expect.objectContaining({ event: 'order.created' }));

• Tests d'observabilité : vérifier qu'un span est créé. Utilise @opentelemetry/sdk-trace-base InMemorySpanExporter :

import { InMemorySpanExporter, SimpleSpanProcessor } from '@opentelemetry/sdk-trace-base';
const exporter = new InMemorySpanExporter();
// register, run, expect(exporter.getFinishedSpans().map(s => s.name)).toContain('OrdersService.create');

🎬 Cas d'usage concrets

Scénario 1 — Observabilité d'un assistant juridique LLM

Qui : LegalTech française qui propose un assistant IA pour avocats (résumé d'arrêts, génération de conclusions). Pipeline : ingestion document → embeddings → retrieval → LLM (Claude / GPT) → réponse. Problème : un user signale "la réponse a halluciné un article de loi". Sans observabilité fine, impossible de remonter au prompt exact, aux chunks retrieves, à la version du modèle. La direction veut tracer chaque étape pour répondre aux questions des avocats clients.

// llm.service.ts
import { trace, SpanStatusCode } from '@opentelemetry/api';

const tracer = trace.getTracer('llm');

@Injectable()
export class LegalAssistantService {
  async answer(question: string, userId: string) {
    const start = Date.now();
    return tracer.startActiveSpan('legal_assistant.answer', async (span) => {
      span.setAttributes({ 'user.id': userId, 'question.length': question.length });

      const chunks = await tracer.startActiveSpan('retrieval', async (s) => {
        const res = await this.vectorDb.search(question, { topK: 8 });
        s.setAttributes({ 'retrieval.count': res.length, 'retrieval.score.top': res[0]?.score ?? 0 });
        s.end();
        return res;
      });

      const answer = await tracer.startActiveSpan('llm.completion', async (s) => {
        s.setAttributes({ 'gen_ai.system': 'anthropic', 'gen_ai.request.model': 'claude-opus-4-8', 'llm.input_tokens': estimateTokens(question, chunks) });
        try {
          const res = await this.claude.complete({ question, chunks });
          s.setAttributes({
            'gen_ai.usage.input_tokens': res.usage.inputTokens,
            'gen_ai.usage.output_tokens': res.usage.outputTokens,
            'gen_ai.response.finish_reasons': [res.stopReason],
          });
          s.end();
          return res.text;
        } catch (e) {
          s.recordException(e as Error);
          s.setStatus({ code: SpanStatusCode.ERROR });
          s.end();
          throw e;
        }
      });

      this.logger.log({
        event: 'legal.answer.generated',
        userId,
        chunkIds: chunks.map(c => c.id),
        model: 'claude-opus-4-8',
        latencyMs: Date.now() - start,
      });
      span.end();
      return answer;
    });
  }
}

Gains : quand un avocat client signale une hallucination, on retrouve dans Tempo la trace complète : les 8 chunks retrieves (avec leurs IDs et scores), le prompt assemblé, la réponse Claude avec son finish_reason. L'équipe a découvert que 30% des hallucinations venaient d'un chunk de jurisprudence mal scannée (OCR foireux) — une fois le source data nettoyé, taux d'hallucination divisé par 4.

Note conventions — Les attributs gen_ai.* (gen_ai.system, gen_ai.request.model, gen_ai.usage.input_tokens, gen_ai.usage.output_tokens, gen_ai.response.finish_reasons) sont les semantic conventions OpenTelemetry pour les LLM. Préfère-les à des attributs maison (llm.model, llm.tokens) : les backends (Tempo, Honeycomb, Datadog, Grafana) ont des vues GenAI pré-câblées dessus, et tu obtiens gratuitement le coût par span (input × prix_input + output × prix_output). Pour claude-opus-4-8 : input $5/MTok, output $25/MTok. Loggue toujours gen_ai.usage.* sur le span LLM — sans ça, impossible de répondre à "quel endpoint brûle le budget Anthropic ?".

Scénario 2 — Request tracing dans un e-commerce multi-services

Qui : marketplace française à 8 services backend (catalog, cart, checkout, payments, shipping, accounts, search, recommendations). Pic à 600 req/s. Problème : un client signale "ma commande a mis 12s à se créer". Lequel des 8 services est en cause ? Sans traceId partagé, l'analyse est un calvaire — chaque équipe consulte ses logs séparément, personne ne corrèle.

// shared/correlation.middleware.ts
import { Injectable, NestMiddleware } from '@nestjs/common';
import { AsyncLocalStorage } from 'node:async_hooks';
import { randomUUID } from 'node:crypto';
import { context, propagation, trace } from '@opentelemetry/api';

type Ctx = { traceId: string; userId?: string; tenantId?: string };
export const als = new AsyncLocalStorage<Ctx>();

@Injectable()
export class CorrelationMiddleware implements NestMiddleware {
  use(req: any, res: any, next: any) {
    const traceparent = req.headers.traceparent;
    const otelCtx = traceparent ? propagation.extract(context.active(), req.headers) : context.active();
    const span = trace.getSpan(otelCtx);
    const traceId = span?.spanContext().traceId ?? randomUUID().replace(/-/g, '');
    res.setHeader('x-trace-id', traceId);
    als.run({ traceId, userId: req.user?.sub, tenantId: req.headers['x-tenant-id'] }, () => {
      context.with(otelCtx, () => next());
    });
  }
}

Gains : un seul clic dans Grafana fait passer "log d'erreur" → "trace complète" → "spans par service". L'équipe a identifié que le checkout passait par 19 appels DB (N+1 sur les variants produit), résolu en 2h. Le MTTR sur les incidents perf a chuté de 45 min à 8 min en moyenne.

Scénario 3 — OpenTelemetry conforme ACPR pour banque en ligne

Qui : néobanque PME régulée par l'ACPR. Obligation de conserver 13 mois de traces d'opérations bancaires (CRBF 2004-04, articles 12-13). Problème : les logs applicatifs étaient mélangés avec les logs techniques, impossible à isoler proprement pour l'audit. Pas de signature/intégrité non plus.

// audit.interceptor.ts
@Injectable()
export class BankingAuditInterceptor implements NestInterceptor {
  constructor(@Inject('AUDIT_LOGGER') private readonly audit: pino.Logger) {}

  intercept(ctx: ExecutionContext, next: CallHandler) {
    const req = ctx.switchToHttp().getRequest();
    const start = Date.now();
    return next.handle().pipe(
      tap((result) => {
        this.audit.info({
          event: 'banking.operation',
          actor: { userId: req.user?.sub, ip: req.ip, userAgent: req.headers['user-agent'] },
          operation: { method: req.method, path: req.route?.path, params: maskPii(req.params) },
          outcome: 'success',
          traceId: req.traceId,
          tenantId: req.headers['x-tenant-id'],
          latencyMs: Date.now() - start,
          // hash for tamper detection
          integrity: hashChain(result),
          timestamp: new Date().toISOString(),
        });
      }),
      catchError((err) => {
        this.audit.warn({ event: 'banking.operation', outcome: 'failure', error: err.code, traceId: req.traceId });
        throw err;
      }),
    );
  }
}

Gains : journal d'audit séparé en JSON immutable, scrappé par Fluent Bit vers un bucket S3 avec Object Lock (write-once 13 mois). L'auditeur ACPR a reçu un export filtré par utilisateur en 20 minutes lors du contrôle 2025. Le traceId permet de croiser audit + trace + logs sans replier les fichiers à la main.

🛠️ Exemple end-to-end

Mise en situation : tu pilotes l'observabilité d'un service de réservation hôtelière qui appelle un PMS (Property Management System) tiers, une queue BullMQ pour les confirmations, et envoie des emails. Tu veux : pino logs structurés, OpenTelemetry traces avec propagation à travers HTTP et queue, métriques RED par endpoint, et un dashboard Grafana qui montre la latence p99 par opération.

// otel.ts — required BEFORE Nest bootstrap
import { NodeSDK } from '@opentelemetry/sdk-node';
import { getNodeAutoInstrumentations } from '@opentelemetry/auto-instrumentations-node';
import { OTLPTraceExporter } from '@opentelemetry/exporter-trace-otlp-http';
import { PrometheusExporter } from '@opentelemetry/exporter-prometheus';
import { resourceFromAttributes } from '@opentelemetry/resources';
import {
  ATTR_SERVICE_NAME,
  ATTR_SERVICE_VERSION,
} from '@opentelemetry/semantic-conventions';
import {
  ATTR_DEPLOYMENT_ENVIRONMENT_NAME,
} from '@opentelemetry/semantic-conventions/incubating';
import {
  ParentBasedSampler,
  TraceIdRatioBasedSampler,
} from '@opentelemetry/sdk-trace-base';

const sdk = new NodeSDK({
  // `resourceFromAttributes` + `ATTR_*` string constants replace the deprecated
  // `new Resource({...})` + `SemanticResourceAttributes` enum (removed in @opentelemetry/resources ≥ 2.x).
  resource: resourceFromAttributes({
    [ATTR_SERVICE_NAME]: 'bookings-api',
    [ATTR_SERVICE_VERSION]: process.env.APP_VERSION ?? 'dev',
    [ATTR_DEPLOYMENT_ENVIRONMENT_NAME]: process.env.NODE_ENV ?? 'dev',
  }),
  traceExporter: new OTLPTraceExporter({
    url: process.env.OTEL_EXPORTER_OTLP_ENDPOINT ?? 'http://otel-collector:4318/v1/traces',
  }),
  metricReader: new PrometheusExporter({ port: 9464 }),
  // Wrap in ParentBasedSampler: a child span must inherit the root's keep/drop decision,
  // otherwise a sampled trace can have holes (root kept, children independently dropped).
  sampler: new ParentBasedSampler({
    root: new TraceIdRatioBasedSampler(process.env.NODE_ENV === 'production' ? 0.1 : 1.0),
  }),
  instrumentations: [
    getNodeAutoInstrumentations({
      '@opentelemetry/instrumentation-fs': { enabled: false },
      '@opentelemetry/instrumentation-http': { ignoreIncomingRequestHook: (req) => req.url === '/health/liveness' },
    }),
  ],
});

sdk.start();
process.on('SIGTERM', () => sdk.shutdown().finally(() => process.exit(0)));

// src/main.ts
import 'reflect-metadata';
import { NestFactory } from '@nestjs/core';
import { LoggerErrorInterceptor, Logger } from 'nestjs-pino';
import { AppModule } from './app.module';

async function bootstrap() {
  const app = await NestFactory.create(AppModule, { bufferLogs: true });
  app.useLogger(app.get(Logger));
  app.useGlobalInterceptors(new LoggerErrorInterceptor());
  await app.listen(3000);
}
bootstrap();

// src/app.module.ts
import { Module, MiddlewareConsumer } from '@nestjs/common';
import { LoggerModule } from 'nestjs-pino';
import { randomUUID } from 'node:crypto';
import { als, CorrelationMiddleware } from './shared/correlation.middleware';

@Module({
  imports: [
    LoggerModule.forRoot({
      pinoHttp: {
        level: process.env.LOG_LEVEL ?? 'info',
        redact: {
          paths: ['req.headers.authorization', 'req.headers.cookie', '*.password', '*.creditCard.number'],
          censor: '[REDACTED]',
        },
        customProps: () => ({
          traceId: als.getStore()?.traceId,
          userId: als.getStore()?.userId,
        }),
        genReqId: (req) => (req.headers['x-request-id'] as string) ?? randomUUID(),
        serializers: {
          req: (req) => ({ id: req.id, method: req.method, url: req.url }),
          res: (res) => ({ statusCode: res.statusCode }),
          err: (err) => ({ name: err.name, message: err.message, code: err.code, stack: err.stack }),
        },
        transport: process.env.NODE_ENV !== 'production' ? { target: 'pino-pretty' } : undefined,
      },
    }),
    BookingsModule,
  ],
})
export class AppModule {
  configure(consumer: MiddlewareConsumer) {
    consumer.apply(CorrelationMiddleware).forRoutes('*');
  }
}

// src/bookings/bookings.service.ts
import { Injectable, Logger } from '@nestjs/common';
import { trace, context, propagation, SpanStatusCode } from '@opentelemetry/api';
import { metrics } from '@opentelemetry/api';

const tracer = trace.getTracer('bookings');
const meter = metrics.getMeter('bookings');
const bookingsCreated = meter.createCounter('bookings_created_total');
const bookingLatency = meter.createHistogram('booking_creation_duration_ms', { unit: 'ms' });

@Injectable()
export class BookingsService {
  private readonly logger = new Logger(BookingsService.name);

  constructor(
    private readonly pms: PmsClient,
    private readonly queue: BookingsQueue,
    private readonly db: BookingsRepository,
  ) {}

  async create(dto: CreateBookingDto, userId: string) {
    const start = Date.now();
    return tracer.startActiveSpan('booking.create', async (span) => {
      span.setAttributes({
        'booking.hotel_id': dto.hotelId,
        'booking.nights': dto.nights,
        'user.id': userId,
      });
      try {
        const availability = await tracer.startActiveSpan('pms.check_availability', async (s) => {
          const res = await this.pms.checkAvailability(dto.hotelId, dto.checkIn, dto.nights);
          s.setAttributes({ 'pms.available': res.available, 'pms.rate': res.rate });
          s.end();
          return res;
        });

        if (!availability.available) {
          span.setStatus({ code: SpanStatusCode.ERROR, message: 'no_availability' });
          span.end();
          throw new ConflictException('no_availability');
        }

        const booking = await this.db.create({ ...dto, userId, rate: availability.rate });

        // propagate trace context into queue payload
        const carrier: Record<string, string> = {};
        propagation.inject(context.active(), carrier);
        await this.queue.enqueueConfirmation({ bookingId: booking.id, _otel: carrier });

        bookingsCreated.add(1, { hotel: dto.hotelId, channel: 'web' });
        bookingLatency.record(Date.now() - start, { outcome: 'success' });
        this.logger.log({ event: 'booking.created', bookingId: booking.id, hotelId: dto.hotelId, rate: availability.rate });
        span.end();
        return booking;
      } catch (e) {
        span.recordException(e as Error);
        span.setStatus({ code: SpanStatusCode.ERROR });
        bookingLatency.record(Date.now() - start, { outcome: 'failure' });
        span.end();
        throw e;
      }
    });
  }
}

// src/bookings/confirmation.worker.ts — BullMQ worker that continues the trace
import { Worker } from 'bullmq';
import { context, propagation, trace } from '@opentelemetry/api';

const tracer = trace.getTracer('bookings-worker');

new Worker('booking-confirmation', async (job) => {
  const parentCtx = propagation.extract(context.active(), job.data._otel ?? {});
  return context.with(parentCtx, () =>
    tracer.startActiveSpan('confirmation.send', async (span) => {
      span.setAttributes({ 'booking.id': job.data.bookingId });
      try {
        await sendConfirmationEmail(job.data.bookingId);
        await sendSmsConfirmation(job.data.bookingId);
        span.end();
      } catch (e) {
        span.recordException(e as Error);
        span.end();
        throw e;
      }
    }),
  );
}, { connection: { url: process.env.REDIS_URL! } });

Effets concrets : un POST /bookings qui crashe à 12s produit dans Grafana Tempo une trace complète (HTTP server → DB → PMS HTTP → queue enqueue → worker → email → SMS). La métrique booking_creation_duration_ms montre que le p99 explose à 8s quand le PMS est lent — alerte Prometheus déclenchée à p99 > 2s pendant 5min. Le log event=booking.created filtré par userId permet au support de retrouver toutes les actions d'un client en 10s.

🔁 Quand utiliser / éviter

• Logs structurés JSON : toujours dès staging. Dev local en pretty-print.
• OTel : dès le 2e service. Pour une app mono, Pino + logs suffisent souvent jusqu'à 10k req/min.
• Prometheus scraping : standard cloud-native. Évite si tu es full-managed (Datadog, NewRelic) qui imposent leur agent.
• APM commercial (Datadog, NewRelic, Honeycomb) : si tu veux moins de plomberie, paies. Open source si tu veux contrôler la rétention.
• Évite Winston sur les hot paths — 5–10x plus lent que Pino, surtout en JSON.
• Évite les logs verbeux par défaut — debug désactivé en prod, activable par feature flag ou par module pour debug ciblé.

Distributed tracing — propagation patterns

Quand un service A appelle un service B, le traceId doit suivre. OTel standardise via les headers W3C :

traceparent: 00-<trace-id>-<parent-span-id>-<flags>
tracestate: vendor1=value,vendor2=value

Si tu utilises axios ou undici instrumenté par OTel, c'est automatique. Sinon, propage à la main :

import { trace, context, propagation } from '@opentelemetry/api';

const headers: Record<string, string> = {};
propagation.inject(context.active(), headers);
await fetch(url, { headers });

Côté receiver, l'instrumentation HTTP extrait automatiquement et continue la trace. Si tu vois "deux traces séparées" dans Tempo, c'est que la propagation est cassée — vérifie les headers passés par tes clients.

Pour les queues (BullMQ, RabbitMQ), pas de propagation auto par défaut. Pattern :

// producer
const headers: Record<string, string> = {};
propagation.inject(context.active(), headers);
await queue.add('process', { payload, _otel: headers });

// consumer
const ctx = propagation.extract(context.active(), job.data._otel);
context.with(ctx, async () => {
  // span créé ici hérite du parent
  await processJob(job.data.payload);
});

🤖 Observer un agent LLM servi depuis NestJS

C'est le cas le plus piégeux pour un staff engineer : un endpoint LLM streamé n'a pas une latence, il en a trois (TTFB, débit inter-token, durée totale) ; il coûte de l'argent réel par requête ; et il peut être annulé en plein vol par le client. Une instru "HTTP RED" classique ne voit rien de tout ça — la requête SSE reste "en cours" 30s, le coût n'apparaît nulle part, et une annulation client ressemble à un succès. Voici comment un senior câble l'observabilité d'un agent.

Les 4 métriques qui comptent vraiment (au-delà de RED)

Métrique	Pourquoi	Type OTel	Labels (cardinalité faible !)
TTFB (time-to-first-token)	C'est la latence perçue en streaming. p99 > 2s = UX morte.	Histogram	route, model
Tokens out / req	Pilote le coût ET la durée. Une dérive = prompt qui part en boucle.	Histogram	model, finish_reason
Coût $ / req	Le seul KPI que le CFO regarde. input×prix_in + output×prix_out.	Histogram	model, route
Taux d'annulation	Client qui ferme l'onglet = tokens gaspillés. Invisible en RED.	Counter	route, reason (client_abort / timeout / error)

⚠️ Jamais userId ou promptHash en label de metric — explosion de cardinalité Prometheus. Le userId va dans le span (haute cardinalité OK) et dans le log, pas dans la metric.

DI'd LLM client — pas de new Anthropic() dans un champ

Le client Anthropic doit être injecté via forRootAsync (config-driven, retries SDK activés, testable/mockable). Le mettre en private claude = new Anthropic() dans un service casse les tests et duplique les connexions.

// anthropic.module.ts
import Anthropic from '@anthropic-ai/sdk';
import { Module, Global } from '@nestjs/common';
import { ConfigModule, ConfigService } from '@nestjs/config';

export const ANTHROPIC = Symbol('ANTHROPIC');

@Global()
@Module({
  imports: [ConfigModule],
  providers: [{
    provide: ANTHROPIC,
    inject: [ConfigService],
    useFactory: (cfg: ConfigService) =>
      new Anthropic({
        apiKey: cfg.getOrThrow('ANTHROPIC_API_KEY'),
        maxRetries: 3,        // le SDK retry 429/5xx avec backoff exponentiel + jitter
        timeout: 60_000,
      }),
  }],
  exports: [ANTHROPIC],
})
export class AnthropicModule {}

Le span agentique + le streaming SSE + l'AbortController

L'instrumentation auto ne sait pas tracer le contenu d'un appel LLM. Tu crées le span à la main, tu enregistres l'usage à la fin du stream (pas avant — tu ne connais pas output_tokens au début), et tu branches l'annulation client sur l'AbortController du SDK pour ne pas continuer à brûler des tokens après un disconnect.

// chat.controller.ts
import { Controller, Post, Body, Res, Req, Inject } from '@nestjs/common';
import type { Response, Request } from 'express';
import Anthropic from '@anthropic-ai/sdk';
import { trace, metrics, SpanStatusCode } from '@opentelemetry/api';
import { ANTHROPIC } from './anthropic.module';

const tracer = trace.getTracer('chat');
const meter = metrics.getMeter('chat');
const ttfb = meter.createHistogram('llm_ttfb_ms', { unit: 'ms' });
const tokensOut = meter.createHistogram('llm_output_tokens');
const costUsd = meter.createHistogram('llm_cost_usd', { unit: 'usd' });
const aborts = meter.createCounter('llm_aborts_total');

// claude-opus-4-8 : $5 / MTok in, $25 / MTok out
const price = (usage: Anthropic.Usage) =>
  (usage.input_tokens * 5 + usage.output_tokens * 25) / 1_000_000;

@Controller('chat')
export class ChatController {
  constructor(@Inject(ANTHROPIC) private readonly claude: Anthropic) {}

  @Post('stream')
  async stream(@Body() dto: ChatDto, @Req() req: Request, @Res() res: Response) {
    res.set({ 'Content-Type': 'text/event-stream', 'Cache-Control': 'no-cache', Connection: 'keep-alive' });

    // Annulation : si le client ferme la socket, on coupe l'appel SDK (sinon on paie le reste)
    const ac = new AbortController();
    req.on('close', () => ac.abort());

    await tracer.startActiveSpan('chat.stream', async (span) => {
      span.setAttributes({ 'gen_ai.system': 'anthropic', 'gen_ai.request.model': 'claude-opus-4-8', 'user.id': dto.userId });
      const start = Date.now();
      let firstToken = false;

      try {
        const stream = this.claude.messages.stream(
          {
            model: 'claude-opus-4-8',
            max_tokens: 4096,
            // adaptive thinking : le modèle décide quand/combien raisonner.
            // display:'summarized' sinon les blocs thinking arrivent vides (défaut 'omitted' sur Opus 4.8),
            // ce qui ressemble à une longue pause avant le premier token côté UI.
            thinking: { type: 'adaptive', display: 'summarized' },
            output_config: { effort: 'high' },   // low|medium|high|xhigh|max — pilote profondeur + coût
            messages: dto.messages,
          },
          { signal: ac.signal },          // <-- le SDK propage l'abort jusqu'à fetch()
        );

        for await (const ev of stream) {
          if (ev.type === 'content_block_delta' && ev.delta.type === 'text_delta') {
            if (!firstToken) { firstToken = true; ttfb.record(Date.now() - start, { route: 'chat', model: 'claude-opus-4-8' }); }
            res.write(`data: ${JSON.stringify({ text: ev.delta.text })}\n\n`);
          }
        }

        const final = await stream.finalMessage();
        tokensOut.record(final.usage.output_tokens, { model: 'claude-opus-4-8', finish_reason: final.stop_reason ?? 'null' });
        costUsd.record(price(final.usage), { model: 'claude-opus-4-8', route: 'chat' });
        span.setAttributes({
          'gen_ai.usage.input_tokens': final.usage.input_tokens,
          'gen_ai.usage.output_tokens': final.usage.output_tokens,
          'gen_ai.response.finish_reasons': [final.stop_reason ?? 'null'],
        });
        res.write('data: [DONE]\n\n');
        res.end();
      } catch (e) {
        if (ac.signal.aborted) {
          aborts.add(1, { route: 'chat', reason: 'client_abort' });
          span.setAttribute('llm.aborted', true);   // PAS une erreur : c'est un comportement normal, à ne pas alerter
        } else {
          span.recordException(e as Error);
          span.setStatus({ code: SpanStatusCode.ERROR });
          aborts.add(1, { route: 'chat', reason: 'error' });
          if (!res.headersSent) res.status(500);
          res.end();
        }
      } finally {
        span.end();
      }
    });
  }
}

TTFB avec thinking activé. Ce code mesure le TTFB au premier text_delta — c'est le bon choix UX (le premier token de réponse perçu). Mais avec thinking: 'adaptive', le modèle émet d'abord des content_block_delta de type thinking_delta : si tu les streames dans une bulle "réflexion", mesure aussi un ttft_thinking (premier thinking_delta) — sinon ton TTFB "réponse" inclut tout le temps de raisonnement et tu confonds "modèle lent à démarrer" avec "modèle qui réfléchit longtemps". Deux histogrammes séparés, deux diagnostics différents.

Points seniors dans ce code :

1. req.on('close') → ac.abort() : un client qui ferme l'onglet ne doit pas te coûter 4096 tokens. C'est le bug le plus cher en prod LLM. Tu le mesures via llm_aborts_total{reason="client_abort"}.
2. L'annulation n'est PAS une erreur : span.setAttribute('llm.aborted', true) mais surtout pas SpanStatusCode.ERROR — sinon ton taux d'erreur explose artificiellement et tu te fais réveiller la nuit pour des gens qui ferment leur navigateur.
3. L'usage se loggue à la fin (stream.finalMessage()), car output_tokens n'existe pas avant la fin du stream.
4. finish_reason (stop_reason) est un label clé : un pic de max_tokens = prompts qui tronquent ; un refusal (Claude décline) doit remonter en dashboard, pas en erreur 500.

La boucle tool-use (agentic) : un span par itération

Un agent qui appelle des outils boucle model → tool → model. Sans instru, une boucle infinie ressemble à "une requête lente". Le pattern : un span enfant par itération, avec un compteur d'itérations comme garde-fou observable.

async runAgent(messages, tools) {
  return tracer.startActiveSpan('agent.loop', async (loopSpan) => {
    let iterations = 0;
    while (true) {
      if (++iterations > 10) {                       // garde-fou : alerte si on atteint le plafond
        loopSpan.setAttribute('agent.max_iterations_hit', true);
        break;
      }
      const res = await tracer.startActiveSpan(`agent.turn.${iterations}`, async (s) => {
        const r = await this.claude.messages.create({ model: 'claude-opus-4-8', max_tokens: 4096, messages, tools });
        s.setAttributes({ 'gen_ai.usage.output_tokens': r.usage.output_tokens, 'agent.stop_reason': r.stop_reason });
        s.end();
        return r;
      });
      if (res.stop_reason !== 'tool_use') { messages.push({ role: 'assistant', content: res.content }); break; }
      // exécute les tools, push les tool_result, on reboucle...
    }
    loopSpan.setAttribute('agent.iterations', iterations);
    loopSpan.end();
  });
}

L'attribut agent.iterations sur le span racine te donne, en une requête PromQL/TraceQL, la distribution du nombre de tours par agent — le signal n°1 d'un agent qui part en vrille.

Observer le thinking (adaptive thinking / effort). Sur claude-opus-4-8, tu actives le raisonnement avec thinking: { type: 'adaptive' } et tu pilotes la profondeur via output_config: { effort: 'high' } (et non plus budget_tokens, retiré sur Opus 4.7/4.8 — il renvoie un 400). Le piège d'observabilité : les thinking tokens sont facturés comme des output tokens mais n'apparaissent pas dans le texte streamé. final.usage.output_tokens les inclut déjà — donc ton costUsd est correct — mais si tu veux isoler le coût du raisonnement, loggue effort en attribut de span (output.effort) et corrèle : un passage de medium à xhigh peut tripler les output tokens sur les requêtes agentiques. Côté borne dure, garde un task_budget (output_config: { task_budget: { type: 'tokens', total: N } }, beta) que le modèle voit décrémenter et auto-modère — distinct de max_tokens, qui est un plafond non visible du modèle. Pour une boucle agentique, task_budget borne le coût cumulé sur tous les tours ; effort règle la profondeur par tour.

BullMQ : jobs LLM idempotents et cost-aware

Pour les générations longues (batch, async), tu passes par BullMQ. Trois disciplines seniors :

• Idempotence keyée sur une generationId : jobId: generationId. Si un retry rejoue le job, tu ne paies pas deux fois Anthropic. Avant l'appel LLM, check une clé Redis result:${generationId} ; si présente, court-circuite.
• Retry cost-aware : ne retry que les erreurs transitoires (429, 5xx, overloaded_error, APIConnectionError). Un 400 invalid_request_error ou un refusal ne se retry jamais — tu paies pour rien. Le SDK gère déjà le backoff sur 429/5xx via maxRetries, donc côté BullMQ ne re-retry pas par-dessus.
• Partial-output : si le worker crashe en plein stream, persiste le buffer partiel sous partial:${generationId} pour reprendre / afficher au lieu de tout jeter. Loggue event: 'llm.partial_saved' avec le nombre de tokens déjà émis.

Le refusal n'est pas une erreur — c'est un signal métier. Sur claude-opus-4-8, un appel peut revenir en HTTP 200 avec stop_reason: 'refusal' (les classifieurs de sécurité déclinent la requête). Code naïf qui lit res.content[0].text → crash. Discipline senior : checke res.stop_reason avant de lire content, loggue event: 'llm.refusal' avec stop_details.category (cyber, bio, …), et incrémente un counter llm_refusals_total{category} — jamais en erreur 5xx (sinon tu réveilles l'astreinte pour un comportement attendu, exactement comme l'abort client). Un refus avant tout output n'est pas facturé ; un refus en plein stream facture le partiel déjà émis (à jeter). Ne le retry jamais sur le même modèle — c'est du budget brûlé. Si tu veux un fallback automatique, le paramètre serveur fallbacks: [{ model: 'claude-opus-4-8' }] (beta server-side-fallback-2026-06-01) re-sert la requête sur un autre modèle dans le même appel ; un bloc fallback dans content marque le point de bascule, et usage.iterations te dit qui a vraiment servi la réponse — deux attributs de span précieux pour comprendre ta facture.

@Processor('llm-gen')
export class GenWorker {
  async process(job: Job<{ generationId: string; messages: any[] }>) {
    const { generationId } = job.data;
    const cached = await this.redis.get(`result:${generationId}`);
    if (cached) return JSON.parse(cached);   // idempotence : pas de double appel/double coût

    return tracer.startActiveSpan('llm.gen', async (span) => {
      span.setAttribute('gen_ai.generation_id', generationId);
      try {
        const res = await this.claude.messages.create({ model: 'claude-opus-4-8', max_tokens: 8192, messages: job.data.messages });
        await this.redis.set(`result:${generationId}`, JSON.stringify(res), 'EX', 86400);
        span.setAttribute('gen_ai.usage.output_tokens', res.usage.output_tokens);
        return res;
      } catch (e) {
        const retryable = e instanceof Anthropic.APIError && [429, 500, 503, 529].includes(e.status ?? 0);
        span.recordException(e as Error);
        span.setAttribute('llm.retryable', retryable);
        if (!retryable) job.discard();   // 400 / refusal : on ne brûle pas de budget en boucle
        throw e;
      } finally {
        span.end();
      }
    });
  }
}

Garde-fous à l'edge (avant même d'appeler le LLM)

Un endpoint LLM exposé sans garde-fou, c'est une facture Anthropic ouverte à tous les vents. Trois middlewares/guards, dans l'ordre :

1. Rate-limit par user/clé (@nestjs/throttler ou token-bucket Redis) — borne le nombre de requêtes.
2. Cost-guard : un guard qui vérifie un budget mensuel (spend:${userId} en Redis, incrémenté par le coût réel post-génération). Au-delà, 429 avant l'appel LLM.
3. Idempotency-key au niveau HTTP (Idempotency-Key header) : déduplique les double-clics et les retries réseau côté client, avant de dépenser un token.

Toutes ces décisions se loggent (event: 'llm.ratelimited', event: 'llm.budget_exceeded') avec le traceId — pour qu'un support puisse expliquer en 10s pourquoi un user a été bloqué.

🏋️ Exercices

Progression : implémente → rends-le production-grade → casse-le puis répare. Fais-les dans l'ordre, chacun s'appuie sur le précédent.

1. Le correlationId qui traverse tout (implémente)

Objectif : un traceId unique part du middleware, traverse ALS, et apparaît dans chaque log d'une requête POST /orders qui touche 2 services + 1 query DB.

Indice/Solution : CorrelationMiddleware qui lit x-trace-id ou génère un randomUUID, als.run({ traceId }, next). customProps de pino lit als.getStore()?.traceId. Vérifie : curl -H 'x-trace-id: abc' ... → tous les logs JSON contiennent "traceId":"abc". Piège à valider : un setTimeout/Promise.all casse-t-il la propagation ? (Non avec ALS — c'est tout l'intérêt.)

2. Span LLM avec usage + coût (production-grade)

Objectif : instrumente un endpoint /chat non-streamé qui appelle claude-opus-4-8, et expose dans Grafana un dashboard "coût $ par route" via les attributs gen_ai.* et une metric llm_cost_usd.

Indice/Solution : span chat.completion avec gen_ai.usage.input_tokens / output_tokens / gen_ai.response.finish_reasons. Histogram costUsd calculé (in×5 + out×25)/1e6. Labels model + route uniquement (pas de userId !). Vérifie la cardinalité : count(count by (...) (llm_cost_usd)) doit rester < quelques dizaines de séries.

3. Streaming + AbortController (production-grade)

Objectif : passe l'endpoint en SSE, mesure le TTFB, et garantis qu'une fermeture client (req.on('close')) coupe l'appel SDK et incrémente llm_aborts_total{reason="client_abort"} — sans compter ça comme une erreur.

Indice/Solution : this.claude.messages.stream(params, { signal: ac.signal }). Enregistre ttfb au premier text_delta. Dans le catch, distingue ac.signal.aborted (abort = span.setAttribute('llm.aborted', true), pas ERROR) du vrai crash (recordException + ERROR). Test : curl --max-time 0.5 puis vérifie que la facturation Anthropic s'arrête (le span montre des output_tokens partiels, pas 4096).

4. La boucle agentique qui part en vrille (casse-le puis répare)

Objectif : écris un agent tool-use qui boucle, puis introduis volontairement un outil qui renvoie toujours "réessaie" → l'agent boucle à l'infini. Détecte-le uniquement via l'observabilité, puis corrige.

Indice/Solution : sans instru, ça ressemble à "une requête lente de 90s". Avec un span enfant par tour + attribut agent.iterations sur le span racine, tu vois iterations=10 (plafond atteint) dans Tempo. Fix : garde-fou if (++iterations > N) break + alerte Prometheus sur agent_max_iterations_hit_total. Bonus : ajoute un task_budget côté Anthropic pour que le modèle s'auto-modère.

5. Tail-based sampling pour ne garder que ce qui compte (scale)

Objectif : ta facture Tempo explose à 600 req/s. Configure le collector OTel pour garder 100% des traces avec erreur ou latence > p99, et 5% du reste.

Indice/Solution : tail_sampling processor dans le collector avec policies status_code = ERROR + latency > 2000ms + probabilistic 5%. Le piège senior : le tail-sampling bufferise toute la trace en mémoire sur le collector → dimensionne num_traces et la RAM, et place le collector après l'app (pas de décision dans le SDK). Mesure : volume de spans exportés divisé par ~15, zéro trace d'erreur perdue.

6. PII leak + audit immutable (casse-le puis répare)

Objectif : loggue volontairement un Authorization header et un prompt contenant un email. Détecte la fuite, puis verrouille : redaction pino + journal d'audit séparé write-once.

Indice/Solution : redact: { paths: ['req.headers.authorization', 'req.headers.cookie', '*.email', 'messages[*].content'], censor: '[REDACTED]' }. Pour l'audit : logger pino dédié → Fluent Bit → S3 Object Lock (write-once N mois). Vérifie qu'un grep -i bearer sur les logs exportés ne retourne rien. Question piège : pourquoi redacter aussi le contenu du prompt d'un agent LLM ? (RGPD : un prompt utilisateur est de la donnée perso.)

7. Le refusal qui réveille l'astreinte (casse-le puis répare)

Objectif : un dashboard "taux d'erreur LLM" passe au rouge à 3h du matin et déclenche une alerte PagerDuty. En enquêtant, tu découvres que ce ne sont pas des erreurs : claude-opus-4-8 a décliné une série de requêtes (stop_reason: 'refusal') qu'un code naïf comptait comme des 5xx. Sépare le signal, puis garantis qu'un refus ne déclenche plus jamais d'alerte d'erreur.

Indice/Solution : le bug est un catch (ou un mapping de status) qui traite tout non-end_turn comme une erreur. Checke res.stop_reason === 'refusal' avant de lire res.content[0], route-le vers llm_refusals_total{category} (depuis res.stop_details.category) et event: 'llm.refusal', et retire-le du calcul du taux d'erreur Prometheus (sum(rate(llm_errors_total[5m])) ne doit compter que les vraies exceptions). Piège senior : un refus en plein stream a déjà facturé du partiel — loggue gen_ai.usage.output_tokens du partiel pour le voir dans la facture, puis jette-le. Bonus : ajoute le paramètre serveur fallbacks: [{ model: 'claude-opus-4-8' }] et vérifie via le bloc content de type fallback + usage.iterations que la requête a bien été re-servie sans repasser par l'astreinte.

🎤 En entretien

Q : Pourquoi AsyncLocalStorage plutôt qu'un @Injectable({ scope: REQUEST }) pour porter le traceId ? Un provider request-scoped force NestJS à recréer tout l'arbre de dépendances par requête (coût perf + impossible d'injecter dans un singleton). ALS porte le contexte de manière transparente à travers la stack async sans toucher la DI ni les signatures de méthodes. Le seul angle mort : ALS ne traverse pas les worker_threads — là il faut passer le traceId explicitement dans le message.

Q : Logs, metrics, traces — si tu ne pouvais en garder qu'un en prod, lequel et pourquoi ? Les traces, parce qu'avec OTel elles portent déjà les metrics (RED dérivées de http.server.duration) et que chaque span peut générer un log structuré. Mais c'est un piège : la vraie réponse senior est "ça dépend de la question". Metrics pour savoir qu'il y a un problème (alerting, agrégat bon marché, cardinalité bornée), traces pour savoir où, logs pour savoir quoi exactement. Sans traceId partagé entre les trois, tu as trois écrans qui ne se parlent pas.

Q : Un endpoint LLM streamé a un p99 de latence "normal" mais les users se plaignent. Où regardes-tu ? La latence totale est le mauvais signal pour du streaming. Je regarde le TTFB (time-to-first-token) — c'est ce que l'user perçoit — et le débit inter-token. Un TTFB p99 à 4s avec une durée totale à 8s donne une UX catastrophique même si "8s" semble acceptable. Ensuite je corrèle avec gen_ai.usage.input_tokens : un prompt qui gonfle (RAG mal borné, historique non tronqué) explose le TTFB.

Q : Comment empêches-tu un userId de faire exploser ta cardinalité Prometheus, tout en gardant la capacité de débugger un user précis ? Règle absolue : haute cardinalité (userId, traceId, promptHash) va dans les spans et les logs, jamais dans les labels de metric. Une metric llm_cost_usd{model, route} reste à quelques dizaines de séries ; pour débugger un user, je pivote depuis le log (userId=X) vers sa trace via le traceId. Mettre userId en label = millions de séries = OOM du Prometheus = postmortem garanti.

Q : Ton taux d'erreur d'un endpoint LLM streamé est à 8 %, l'astreinte sonne. Qu'est-ce que tu regardes avant de paniquer ? Trois faux positifs classiques que RED ne distingue pas d'une vraie 5xx, et que je sépare par construction. (1) L'annulation client (req.on('close') → ac.abort()) : l'user a fermé l'onglet — llm_aborts_total{reason="client_abort"}, span llm.aborted=true, pas SpanStatusCode.ERROR. (2) Le refusal : claude-opus-4-8 a décliné en HTTP 200 — llm_refusals_total{category}, jamais en erreur. (3) Le rate-limit / cost-guard à l'edge : on a bloqué avant l'appel — event: 'llm.ratelimited', c'est un 429 attendu. Une vraie erreur, c'est une exception SDK non transitoire ou un 5xx Anthropic après épuisement des retries. Si mes trois compteurs sont propres et que llm_errors_total est plat, l'alerte est mal câblée — elle agrège abort + refusal + throttle dans le numérateur. Le fix est dans la définition de l'alerte, pas dans le code.

🔗 Liens

• nestjs-pino
• OpenTelemetry Node
• W3C Trace Context
• OpenTelemetry GenAI semantic conventions — les attributs gen_ai.* pour tracer les appels LLM
• Grafana Tempo / Loki
• Prometheus best practices
• Livre : Observability Engineering — Charity Majors et al.
• Article : "The Three Pillars with Zero Answers" — Ben Sigelman