Pino logger does not output JSON within NextJS middleware function

[pawelgalazka]

I was planning to use Pino logger within NextJS middleware function:

pages/_middleware.ts

import { NextFetchEvent, NextRequest, NextResponse } from "next/server"
import pino from "pino"

const logger = pino()

export function middleware(req: NextRequest, ev: NextFetchEvent) {
  logger.info("Pino log from middleware")
  return NextResponse.next()
}

Then when I run next dev and request the page, log in no JSON format is printed out:

Pino log from middleware

Weirdly when I use the same logging within any page component:

const logger = pino()

const Home: NextPage = () => {
  logger.info("Pino log from page component")
  return (<div>Test</div>)
})

export default Home

Pino logs in JSON format:

{"level":30,"time":1643780601305,"pid":26203,"hostname":"xxxx.local","msg":"Pino log from page component"}

Not sure what's going. Does NextJS somehow reformat output coming out from middleware functions? 🤔 The same happens for production build with NODE_ENV=production.

[heschong]

I have a similar issue, but ours is pretty-printing JSON and it's driving me crazy:

logger.info({ foo: 'bar', dogs: 'cats' })

comes out as

{
  foo: 'bar',
  dogs: 'cats'
}

(which is not even technically JSON, it's just a pretty-printed js object) and it's kind of driving me crazy. Anyone know how to turn this off?

[icyJoseph]

Having the same issue, in our case Data Dog consumes each line as new log message.

[icyJoseph]

We've landed on something that looks like this:

const logger = pino({
  browser: {
    write(obj) {
      try {
        console.log(JSON.stringify(obj));
      } catch (err) {
        if (err instanceof Error) {
          // Without a `replacer` argument, stringify on Error results in `{}`
          console.log(JSON.stringify(err, ["name", "message", "stack"]));
        } else {
          console.log(JSON.stringify({ message: "Unknown error type" }));
        }
      }
    }
  }
});

Using this while we wait on an alternative.

The problem is that the browser version of pino is being packaged into the _middleware, so we need to tell this version that we want to serialize the output, however, for some reason serialize: true is not working for us, so we use the write option. Since JSON.stringify, is rather resilient (throws only for cycles and BigInt), this patch works swell for now.

[andrewfritz86]

Thanks. This is driving me insane as I am simply trying to log some basic request info to DD in Middleware, and it's taking every newline separated value as a distinct logging message.

[AkshayKumar007]

Having the same issue while using pino logger in middleware, but I'm trying to output the log in server.

[dejanvasic85]

Thanks @icyJoseph that worked...

[AkshayKumar007]

Having the same issue while using pino logger in middleware, but I'm trying to output the log in server.

[ttristan]

Same issue here. I ended up writing a small wrapper to JSON stringify the error and add a level and time to the Log output.
Moreover though, I can not get the Elastic Search Logger to work because I get this error during build:

Dynamic Code Evaluation (e. g. 'eval', 'new Function', 'WebAssembly.compile') not allowed in Middleware src/middleware

[trentonsnyder]

I think this is because the elastic transport uses fast-json-stringify
https://github.com/fastify/fast-json-stringify/blob/master/index.js#L166

[raman-zherdzeu]

Any updates on this issue? I am having the same problem: none of the logs created in my NextJS middlleware are formatted as JSON. Pino-pretty is not working as well. 😢

[icyJoseph]

You can try to import pino from pino/browser, though TS might get angry, though I find it suspicious that the call to require works, but I guess, you are not allowed to call it within the middleware top level.

import { NextResponse } from "next/server";
import pino from "pino/browser";

const logger = pino({ browser: { asObject: true } });

export default async function middleware(req) {
  const { pathname } = req.nextUrl;

  logger.info({ pathname }, "hello from middleware");

  return NextResponse.next();
}

[groves]

I wasn't able to get this to work with import pino from "pino/browser";, but I was still able to configure pino's browser mode to log objects using import pino from "pino";:

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

const log = pino({ browser: { asObject: true } });

export function middleware(request: NextRequest) {
  log.info({ pathname: request.nextUrl.pathname }, "hey");
  return NextResponse.next();
}

[jackliu5]

How is everyone using pino from the middleware at all? I get the You're using a Node.js module (vm) which is not supported in the Edge Runtime. because pino is using fast-redact for redaction which uses the vm module.

[tlenex]

    if (isServer && nextRuntime === 'edge') {
      // pino's dependencies use native node apis,
      // which are not available in the edge runtime,
      // so we're using the browser version of pino here
      // see https://nextjs.org/docs/app/api-reference/edge#unsupported-apis
      config.resolve.alias['pino'] = 'pino/browser.js'
    }

well this kinda does the trick

[myriky]

how about this one?

pino({
  browser: {
    write: (o) => console.log(JSON.stringify(o)),
  },
}).info('Pino info log from middleware');

pino({
  browser: {
    write: (o) => console.log(JSON.stringify(o)),
  },
}).error('Pino error log from middleware');

pino({
  browser: {
    write: (o) => console.log(JSON.stringify(o)),
  },
}).fatal('Pino fatal log from middleware');

const logger = pino({
  browser: {
    write: (o) => console.log(JSON.stringify(o)),
  },
});

logger.child({ '1': '2', '3': '4' }).info('Pino info log from middleware');

[theDanielJLewis]

How are you implementing that code in your middleware? Do you include the full pino code block for your needs, or did you put this in your logger function file?

[sdelano]

To add some context here, the NextJS middleware runs in the edge runtime, which effects more than just pino: #54549

[theDanielJLewis]

Has anyone tested this in Next.js 14?

[Bernix01]

Yes, with next-auth and prisma log keeps behaving weird using this works. As described by @myriky previously

how about this one?

pino({
  browser: {
    write: (o) => console.log(JSON.stringify(o)),
  },
}).info('Pino info log from middleware');

pino({
  browser: {
    write: (o) => console.log(JSON.stringify(o)),
  },
}).error('Pino error log from middleware');

pino({
  browser: {
    write: (o) => console.log(JSON.stringify(o)),
  },
}).fatal('Pino fatal log from middleware');

const logger = pino({
  browser: {
    write: (o) => console.log(JSON.stringify(o)),
  },
});

logger.child({ '1': '2', '3': '4' }).info('Pino info log from middleware');

[Undistraction]

Just to summarise and hopefully save someone some time :

• Next uses its Edge runtime for middleware
• pino-pretty doesn't work on this runtime
• As of 15.2 there is experimental support for Node middleware, but this doesn't seem to resolve this issue.
• You can use the same approach to logging in the browser to format messages logged from the edge runtime
• You can detect whether the runtime is edge using process?.env?.NEXT_RUNTIME === edge``
• You can use this to toggle how you are logging (like you might already be toggling between server and client-side logging)
• Here is an example that is working:

const serverNodeRuntimeConfig = {
  transport: {
    target: `pino-pretty`,
    options: {
      colorize: true,
      messageFormat: `[{group}] {msg}`,
      hideObject: true,
      ignore: `pid,hostname`,
    },
  },
}

const defaultConfig = {
  browser: {
    write: (logObj: unknown) => {
      const { level, msg, group, time, icon } = logObj as Record<string, string>

      const levelUppercased = level.toUpperCase()
      const timeFormatted = format(new Date(time), `HH:mm:ss.sss`)
      const levelColor = getLevelColor(levelUppercased)

      // Output the formatted message using console.log
      console.log(
        `[${timeFormatted}] ${levelColor}${levelUppercased} ${COLOR.CYAN}[${icon} ${group}] ${msg} ${COLOR.WHITE}`
      )
    },
    formatters: {
      level: (label: string) => {
        return {
          level: label,
        }
      },
    },
  },
}

const baseLogger: Logger = pino({
  ...baseConfig,
  ...(ENVIRONMENT.IS_RUNTIME_NODE ? serverNodeRuntimeConfig : defaultConfig),
  // Disable logging on the client unless in development
  enabled: ENVIRONMENT.IS_SERVER || ENVIRONMENT.IS_DEVELOPMENT,
})

[Undistraction]

TLDR pino-pretty needs workers, but even if you have Next configured to use Node for middleware it still doesn't provide access to workers so pino-pretty in middleware is not an option, except in local dev.

[madfcat]

@Undistraction any relevant alternative that will work in app router middleware and across rsc?
or just use pino without pino-pretty?

[Undistraction]

The real answer is that using structured (JSON) logging makes more sense out of dev and especially in production. All pino-pretty is doing is taking structured data and turning it into a more easily scannable string. However it is also annihilating the well structured data that you could have stored in your logs (and could be consumed by other tooling).

Given that you can use pino-pretty in dev, I think the best solution is to check if the app is running locally (or that it isn't running on vercel, by using the envs vercel exposes) and if it's running locally use pino-pretty, and if not, don't.

That way you only use pink pretty in local dev, and staging is production-like in that it uses structured logging.

If you really want pretty logs out of dev, it's very easy to write your own formatter that doesn't use workers, and therefore will work on vercel. However there are performance considerations there (which is exactly why pino-pretty uses workers).

[madfcat]

What do you think about this solution using stream created by pino-pretty and then passed to pino when creating a logger?

import pino from 'pino';
import pretty from 'pino-pretty';

// 1. Create the stream for pino-pretty.
const stream = pretty({ colorize: true, ignore: 'pid,hostname' });

// 2. Create the Pino logger instance, passing the stream directly.
const logger = pino(
	{  level: 'debug' },
	stream
);

[leosilberg]

I wish I had come across this thread sooner instead of trying to get pino-pretty transport to work on middleware even with runtime:"nodejs" set. Thanks @Undistraction for the insights why it doesn't work.

I chose to go with the pino-pretty stream but for older Nextjs versions on the edge runtime the browser config solution is solid