open-telemetry / opentelemetry-js-contrib

OpenTelemetry instrumentation for JavaScript modules
https://opentelemetry.io
Apache License 2.0
643 stars 484 forks source link

How to get Winston Instrumentation to inject span context in a NextJS app #1745

Open Fralleee opened 9 months ago

Fralleee commented 9 months ago

Description

I'm having issues getting Winston Instrumentation to inject the span context correctly in a NextJS application. Some parts work as expected, but I'm facing issues in certain scenarios, particularly when importing the logger in different parts of the application.

Working Setup

I have set up OpenTelemetry and instrumentation as follows:

import { NodeSDK } from "@opentelemetry/sdk-node";
import { OTLPTraceExporter } from "@opentelemetry/exporter-trace-otlp-http";
import { Resource } from "@opentelemetry/resources";
import { SemanticResourceAttributes } from "@opentelemetry/semantic-conventions";
import type { Span } from "@opentelemetry/sdk-trace-node";
import { SimpleSpanProcessor } from "@opentelemetry/sdk-trace-node";
import { WinstonInstrumentation } from "@opentelemetry/instrumentation-winston";

export const registerOTel = (serviceName: string) => {
  const sdk = new NodeSDK({
    resource: new Resource({
      [SemanticResourceAttributes.SERVICE_NAME]: serviceName,
    }),
    spanProcessor: new SimpleSpanProcessor(new OTLPTraceExporter()),

    instrumentations: [
      new WinstonInstrumentation({
        enabled: true,
        logHook(span, record) {
          record["resource.service.name"] = (span as Span).resource.attributes["service.name"];
        },
      }),
    ],
  });

  sdk.start();
};

Calling the test() function after setting up OpenTelemetry works as expected:

export async function test() {
  const { trace } = await import("@opentelemetry/api");
  const winston = await import("winston");
  const { createLogger, transports } = winston;

  const logger = createLogger({
    transports: [new transports.Console()],
  });

  const tracer = trace.getTracer("dsa-web");
  tracer.startActiveSpan("main", (span) => {
    logger.info("Started the span, printing context");
    logger.info(JSON.stringify(span.spanContext()));
    logger.info("In main main spanning");
  });
  logger.info("Ended span in main");
}

Issue

When logging from the default logger within the app later on, it doesn't work as expected.

Here's how the logger is configured:

import { createLogger, transports } from "winston";

export const logger = createLogger({
  transports: [new transports.Console()],
});

And here's how the logger is used in the application:

import { trace } from "@opentelemetry/api";
import { DetailsPageHeader } from "@/components/ui/details-page-header";
import { logger } from "@/logger";

export default function OutsideAccessDomainsPage() {
  const tracer = trace.getTracer("dsa-web");
  tracer.startActiveSpan("main", () => {
    logger.info("Should include stuff");
  });
  return (
    <DetailsPageHeader
      subtitle="Restrict unwanted access from outside domains."
      title="Review X domains with outside access"
    />
  );
}

Question

How can I structure the code to have a single instance of the logger that retains the OpenTelemetry context, allowing span contexts to be correctly injected in a NextJS application?

Any guidance or best practices for setting this up correctly would be immensely appreciated!

Fralleee commented 9 months ago

A working but hacky solution:

import { createLogger, format, transports } from "winston";
import { trace } from "@opentelemetry/api";

const { combine, timestamp, json, printf, splat } = format;

const jsonFormatter = combine(
  splat(),
  timestamp(),
  json(),
);

const configuration = {
  exitOnError: false,
  transports: new transports.Console({
    format: combine(
      jsonFormatter,
      printf((info) => {
        const activeSpan = trace.getActiveSpan();
        const metaData: { span_id?: string; trace_id?: string } = {};
        if (activeSpan) {
          metaData.span_id = activeSpan.spanContext().spanId;
          metaData.trace_id = activeSpan.spanContext().traceId;
        }

        return `[${info.level.toUpperCase()}] ${info["timestamp"]}:  ${info.message}\n${JSON.stringify({ ...info, ...metaData, })}`;
      }),
    ),
  })
};

export const logger = createLogger(configuration);

Not sure if there's any issues by doing it this way.

github-actions[bot] commented 7 months ago

This issue is stale because it has been open 60 days with no activity. Remove stale label or comment or this will be closed in 14 days.