Nextjs instrumentation + pino + dd-trace log injection not working

[zomgbre]

Hi,
I've been trying to get Nextjs instrumentation + pino + dd-trace log injection working to no avail. Looking for some help or maybe it's a bug?

Expected behaviour

I would expect to see logs and traces correlated in Datadog, but they are not. Datadog docs claim to support pino out of the box automatically on this page: https://docs.datadoghq.com/tracing/other_telemetry/connect_logs_and_traces/nodejs/

This enables automatic trace ID injection for bunyan, paperplane, pino, and winston.

There is a note about it having to be in JSON format. From what I can tell, pino is by default JSON format. The logs in datadog appear as JSON in my account.

Actual behaviour

I am getting traces and logs, but they are not correlated. :(

Steps to reproduce

src/instrumentation.ts

export async function register() {
  if (process.env.NEXT_RUNTIME === "nodejs") {
    const tracerLib = await import("dd-trace");
    const tracer = tracerLib.default;

    tracer.init({ logInjection: true });
  }
}

src/logger.ts

import pino from "pino";

export default pino({
    name: "global-logger",
    level: process.env.NEXT_PUBLIC_LOG_LEVEL ?? "info",
    browser: {
        write(obj) {
            console.log(JSON.stringify(obj));
        }
    }
});

Logging is invoked in middleware.ts, server actions, and routes:
src/middleware.ts

import { NextResponse } from "next/server";
import type { NextRequest } from "next/server";
import logger from "./logger";

export const config = {
    matcher: "/((?!api\/health).*)",
};

export async function middleware(request: NextRequest) {
        try {

            // redacted irrelevant code

            logger.info({
                email: "some email",
                url:  request.headers.get("referer")
            }, "request received");

            return  NextResponse.next();
        } catch (e) {
            // redacted irrelevant code
        }
    }
}

app/api/auth/signout.ts

import logger  from "@/logger";
import {  NextResponse } from "next/server";

export function GET(request: Request) {

    // redacted irrelevant code

    logger.info({
        email: "some email",
        url: request.headers.get("referer")
    }, "user signed out");

    return response;
}

We are also using some server actions, but I realize that is alpha :) but here is the gist of it:
https://nextjs.org/docs/app/building-your-application/data-fetching/server-actions

Overall, seems to not be working with my implementation. Looking for guidance or bug fix.

Environment

• Operation system: node:20-alpine
• Node.js version: 20
• Tracer version: 4.11.1
• Agent version: 7
• Relevant library versions:

  "dependencies": {
    "@headlessui/react": "^1.7.16",
    "@heroicons/react": "^2.0.18",
    "@types/node": "20.4.8",
    "@types/react": "18.2.18",
    "@types/react-dom": "18.2.7",
    "autoprefixer": "10.4.14",
    "dd-trace": "^4.11.1",
    "eslint": "8.46.0",
    "eslint-config-next": "13.4.12",
    "jose": "4.14.4",
    "next": "13.4.12",
    "pino": "8.15.0",
    "postcss": "8.4.27",
    "react": "18.2.0",
    "react-dom": "18.2.0",
    "sharp": "^0.32.4",
    "tailwindcss": "3.3.3",
    "typescript": "5.1.6"
  }

[Qard]

TypeScript 5 now builds as ESM by default. I'd recommend checking how you have it configured and see if it's outputting ESM files. If so, you will need to use the loader hook. node --loader dd-trace/loader-hook.mjs your-app.js

[tlhunter]

@zomgbre can you confirm if #3524 (comment) worked for you?

[allyjarjour]

I'm also having this issue @tlhunter. I changed my imports to CJS syntax instead of the loader-hook, which I think should work according to the docs: https://www.npmjs.com/package/dd-trace#experimental-esm-support

[Kevin-McGonigle]

If so, you will need to use the loader hook. node --loader dd-trace/loader-hook.mjs your-app.js

@Qard I'm not sure that's trivial/possible with Next.js. In my case, using the app router, standalone output and the following instrumentation setup:

export async function register(): {
  if (process.env.NEXT_RUNTIME === 'nodejs') {
    const tracerLib = await import('dd-trace');
    const tracer = tracerLib.default;
    tracer.init({ logInjection: true });
  }
}

using node --loader dd-trace/loader-hook.mjs server.js results in the following error:

node:internal/process/esm_loader:34
      internalBinding('errors').triggerUncaughtException(
                                ^
Error [ERR_MODULE_NOT_FOUND]: Cannot find module '/app/node_modules/dd-trace/loader-hook.mjs' imported from /app/
    at finalizeResolution (node:internal/modules/esm/resolve:264:11)
    at moduleResolve (node:internal/modules/esm/resolve:917:10)
    at defaultResolve (node:internal/modules/esm/resolve:1130:11)
    at nextResolve (node:internal/modules/esm/hooks:865:28)
    at Hooks.resolve (node:internal/modules/esm/hooks:303:30)
    at ModuleLoader.resolve (node:internal/modules/esm/loader:358:35)
    at ModuleLoader.getModuleJob (node:internal/modules/esm/loader:240:38)
    at ModuleLoader.import (node:internal/modules/esm/loader:328:34)
    at Hooks.register (node:internal/modules/esm/hooks:164:51)
    at initializeHooks (node:internal/modules/esm/utils:265:17) {
  code: 'ERR_MODULE_NOT_FOUND',
  url: 'file:///app/node_modules/dd-trace/loader-hook.mjs'
}

Presumably, this is due to Next.js's tree-shaking. There is a sizable difference in the contents of the node_modules/dd-trace directory in the standalone build vs. local development.

Local development node_modules/dd-trace:

Standalone build node_modules/dd-trace:

[radum]

Hello everyone, I managed to hit the same dead end like most of you here. I am running Next.js 14 with app router.

The only way I managed to get it working (although not sure if it is fully working yet) is to create a JS file server-preload.js

const packageJSON = require('../package.json');

function setUpDatadogTracing() {
	const tracer = require('dd-trace');

	tracer.init({
		runtimeMetrics: true,
		logInjection: true,
		env: 'dev',
		service: `myapp`,
		version: packageJSON?.version ?? 'unknown'
	});
}

setUpDatadogTracing();

And load it within package.json node -r server-preload.js ./node_modules/.bin/next start. Doing this I don't get only GET and POST in Resources and I have GET /_not-found for 404 pages and GET /about etc etc based on the pages I have.

I am also getting the versioning coming through for each new release I make and also the dev envs are set properly.

Logs are ingested also but only the ones that I am logging via an internal logger I made via Pino. The other ones are not coming in as they are not in JSON format.

There is a way in the file above to patch the console log and make it spit out JSON but that is a can of worms because there is lots of cleaning up that needs to be done to make it work and also it could break at any Next update.

Using the instrumentation hook I never managed to get it working, and using the telemetry from Vercel plus DD I always got undefined errors looking for the _traceID in an object.

Even with this setup I am not sure if I can see any spans and I need to check more.

For sourcemaps I am thinking to generate them and load them via the CI before I remove them from the deployed app.

Has anyone found a better way that works with most DD features and can share their setup?

[vipul0092]

To link/correlate your logs and traces in DD.
You'd need to pass a mixin to pino in which you link the tracer to the log context.

Something like this:

const logger = pino({
   name: 'my-logger',
   level: 'info',
   mixin: (context, _) => {
     const span = tracer?.scope()?.active();
     if (span) {
        tracer.inject(span.context(), 'log', context);
     }
    return context;
  }
});

DD documentation link: https://docs.datadoghq.com/tracing/other_telemetry/connect_logs_and_traces/nodejs/

[radum]

I had the same problem express in this thread. The one thing that did occur to me was that even if we use pino to log to the console, we wrap Pino in our own internal lib. Not sure if that makes a difference but once I updated our internal lib and applied the mixin in pino as per @vipul0092 example all started to work nicely.

The one thing that is still not working is error stacks in Trace results. For a trace in my DD dashboard I can see the error, the logs, everything but under the Errors tab it says missing error message and stack trace. I can see the logs associated under the Logs tab and opening that has the stack trace.

[tlhunter]

Circling back to this issue I believe it mostly boils down to Next.js code loading before the tracer. Here's a document on complex framework usage which I believe will alleviate the core issues. @radum's workaround has a similar effect.

https://docs.datadoghq.com/tracing/trace_collection/compatibility/nodejs/#complex-framework-usage

@zomgbre can you let me know if this solves the issue for you?