v8.3.0 throws "SonicBoom supports only file descriptors and files"

[EvHaus]

After upgrading from 8.2.0 to 8.3.0 my very basic usage of pino is now throwing:

Error: SonicBoom supports only file descriptors and files
 ❯ new SonicBoom node_modules/sonic-boom/index.js:121:11
 ❯ buildSafeSonicBoom node_modules/pino/lib/tools.js:214:18
 ❯ normalizeArgs node_modules/pino/lib/tools.js:308:18
 ❯ Proxy.pino node_modules/pino/pino.js:84:28

My code is:

import pino from 'pino';
const logger = pino();
export default logger;

Rolling back to 8.2.0 makes the problem go away. I looked at the diff between 8.2.0 and 8.3.0 and I can't figure out what's wrong. Could something in the sonic-boom package upgrade be causing this?

[mcollina]

Can you tell me more about the environment you are executing this?

I've executed that kind of code prior to release and everything seemed fine.

[zackheil]

Same was happening to me in a GitHub workflow using ubuntu-latest during unit tests. Will investigate in a bit to see if it is the args I'm passing to Pino that is causing the issue.

[zackheil]

I have isolated the case where it fails in a test. All I did was pass the logger to a function and call one of its methods there. This is the error I get:

Error: SonicBoom supports only file descriptors and files
 ❯ new SonicBoom node_modules/sonic-boom/index.js:121:11
 ❯ buildSafeSonicBoom node_modules/pino/lib/tools.js:214:18
 ❯ normalizeArgs node_modules/pino/lib/tools.js:308:18
 ❯ Proxy.pino node_modules/pino/pino.js:84:28
     82| function pino (...args) {
     83|   const instance = {}
     84|   const { opts, stream } = normalize(instance, caller(), ...args)
       |                            ^
     85|   const {
     86|     redact,
 ❯ new Logger src/logger.ts:12:28
 ❯ src/dummy-helper.spec.ts:4:13

Here is a PR in a dummy repo that adds breaking code in 8.3.0 (checks pass, 8.2.0)

Here is the dependabot PR to update this to 8.3.0 (failing checks, 8.3.0)

[EvHaus]

Can you tell me more about the environment you are executing this?

I'm running inside a Next.js app and testing via Vitest. Here's a minimal reproduction via Vitest: https://stackblitz.com/edit/vitest-dev-vitest-zsjquq

[mcollina]

Ah, I understand the problem now. It's because you are creating a new pino instance within a worker. (every test in vite is created in a worker). I'll fix this as soon as I can.

The fix should be to change process.stdout.fd to process.stdout.fd || 1 in one place and add a test.

[mcollina]

Could you test #1503? This should work.

[zackheil]

That change fixed it for me. Thanks!

[yukha-dw]

Ah, I understand the problem now. It's because you are creating a new pino instance within a worker. (every test in vite is created in a worker). I'll fix this as soon as I can.

The fix should be to change process.stdout.fd to process.stdout.fd || 1 in one place and add a test.

Hello, the problem persists on v8.4.0 when I try to use ava using asynchronous logging to stdout, So i force the value of fd to 1 like yours when initiation pino. I'm not sure how numbers works on SonicBoom options, but defining fd to 1 will still send the output to stdout, right?

const createLogger = (): pino.Logger => {
  const logger = pino(
    {
      level: 'info',
    },
    pino.destination({
      sync: false,
      fd: 1,
    }),
  );

  return logger;
};

[mcollina]

Could you create a repository with a full repro? The latest fix should cover your case too.

[yukha-dw]

Could you create a repository with a full repro? The latest fix should cover your case too.

I've create simple fastify app to reproduce the problem:
https://github.com/ouwyukha/pino-sb-error

I'm able to run ts-node and ava when changing the fd to 1 manually:
https://github.com/ouwyukha/pino-sb-error/blob/31a6d2474494d39950d30741aa685027af7646f6/src/loggerFix.ts#L8-L11

[github-actions]

This issue has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.