Using pino with pino-pretty results in a TypeError at runtime

[net-tech]

What version of Bun is running?

0.8.0+52802a4c556d7498d75d00e4fe4e45633f4283e8

What platform is your computer?

Darwin 22.5.0 arm64 arm

What steps can reproduce the bug?

This bug occurs when using the pino logger package with the popular pino add-on, pino-pretty.

1. Initialise a new bun project with bun init
2. Install pino and pino-pretty via bun add pino && bun add pino-pretty
3. Set up basic repro code:

import { pino } from "pino"

const logger = pino({
	// If you were to remove this whole options object with something like const logger = pino() the error would go away.
	transport: {
		target: "pino-pretty",
	}
})

logger.info("Hello World!")

What is the expected behavior?

The expected behaviour is that the code outputs Hello World! in the console.

What do you see instead?

➜ bun ./index.ts                     
124 |       return join(__dirname, '..', 'file.js')
125 |     }
126 | 
127 |     let fixTarget
128 | 
129 |     for (const filePath of callers) {
                               ^
TypeError: undefined is not an object (evaluating 'callers')
      at fixTarget (/Users/net-tech-/Developer/bun-undefined-callers-repro/node_modules/pino/lib/transport.js:129:27)
      at transport (/Users/net-tech-/Developer/bun-undefined-callers-repro/node_modules/pino/lib/transport.js:114:21)
      at normalizeArgs (/Users/net-tech-/Developer/bun-undefined-callers-repro/node_modules/pino/lib/tools.js:311:15)
      at pino (/Users/net-tech-/Developer/bun-undefined-callers-repro/node_modules/pino/pino.js:87:27)
      at /Users/net-tech-/Developer/bun-undefined-callers-repro/index.ts:3:15

Additional information

No response

[RubberDuckShobe]

Having the same issue on Bun 0.8.1

[jkenda]

Issue also present in Bun 1.0.0:

bun run src/app.ts
124 |       return join(__dirname, '..', 'file.js')
125 |     }
126 |
127 |     let fixTarget
128 |
129 |     for (const filePath of callers) {
                               ^
TypeError: undefined is not an object (evaluating 'callers')
      at fixTarget (/home/jakob/git/jpbb-page/node_modules/pino/lib/transport.js:129:27)
      at transport (/home/jakob/git/jpbb-page/node_modules/pino/lib/transport.js:114:21)
      at normalizeArgs (/home/jakob/git/jpbb-page/node_modules/pino/lib/tools.js:312:15)
      at pino (/home/jakob/git/jpbb-page/node_modules/pino/pino.js:87:27)
      at createPinoLogger (/home/jakob/git/jpbb-page/node_modules/fastify/lib/logger.js:42:13)
      at createLogger (/home/jakob/git/jpbb-page/node_modules/fastify/lib/logger.js:101:17)
      at fastify (/home/jakob/git/jpbb-page/node_modules/fastify/fastify.js:133:32)
      at /home/jakob/git/jpbb-page/src/app.ts:34:12
      at processTicksAndRejections (:1:2602)

[diavrank]

I have the same issue with my Nestjs app.

...
[Nest] 42322   - 09/09/2023, 12:35:32 AM   [ExceptionHandler] undefined is not an object (evaluating 'callers') +40ms
TypeError: undefined is not an object (evaluating 'callers')
    at fixTarget (/Users/myuser/api/node_modules/pino/lib/transport.js:129:10)
    at transport (/Users/myuser/api/node_modules/pino/lib/transport.js:115:30)
    at normalizeArgs (/Users/myuser/api/node_modules/pino/lib/tools.js:311:76)
    at pino (/Users/myuser/api/node_modules/pino/pino.js:88:4)
    at new PinoLogger (/Users/myuser/api/node_modules/nestjs-pino/PinoLogger.js:47:44)
    at <anonymous> (/Users/myuser/api/node_modules/@nestjs/core/injector/injector.js:331:30)
    at instantiateClass (/Users/myuser/api/node_modules/@nestjs/core/injector/injector.js:319:26)
    at <anonymous> (/Users/myuser/api/node_modules/@nestjs/core/injector/injector.js:49:17)

Command run: NODE_ENV=localdev nest start --exec "bun run"

Bun 1.0.0

[AaronDewes]

It looks like WebKit only allows the function it calls for computeErrorInfo, which is what error.stack relies on, to return a string, so this would very likely require WebKit changes.

I submitted a fix to pino as a workaround: pinojs/pino#1804.

[Jarred-Sumner]

The bug is that we aren't calling Error.prepareStackTrace on every time an error stack is generated. Only when Error.captureStackTrace is called. It's fixable on our end

[AaronDewes]

Yes, I just realized the code in WebKit I was looking at was from Bun's patches anyway 😅

I was trying to fix it, but I'm not familiar with WebKit, but I'll experiment a bit more later if you don't fix it in the meantime 😉.

[diavrank]

@Jarred-Sumner only to know, is there an estimated date for the fix? I don't want to press but I'd like to know when to start the migration for my Nestjs app.

[capaj]

The bug is that we aren't calling Error.prepareStackTrace on every time an error stack is generated.

is that a perf optimisation or just a bug?

[capaj]

I hackfixed the problem in pino here:
capaj/pino@8fb80fb

this hackfix does not break any of pino tests: pinojs/pino-pretty#448 (comment)

you can try it out by replacing your "pino": "^8.15.1", with "pino": "github:capaj/pino#master", in package.json

[Jarred-Sumner]

I have manually verified that pino & pino-pretty works in #5802

Once merged (when this issue closes), you can either wait for Bun v1.0.3 or wait an hour and then run bun upgrade --canary

[vtisnado]

Hey @Jarred-Sumner I just checked the bun v1.0.3 release and didn't find any fix for Pino.
Also no new releases for pino or pino-pretty on the last week.

https://github.com/oven-sh/bun/releases/tag/bun-v1.0.3

[zach-betz-hln]

@vtisnado if you try this MRE with latest bun version, what are your results?

[diavrank]

In my case it did work, but I got another error lol:

error: A circular dependency has been detected (property key: "myProp"). Please, make sure that each side of a bidirectional relationships are using lazy resolvers ("type: () => ClassType").

I think is another error which is part of the migration...