[BUG] Pino logger unavailable in nestjs shutdown functions

[dilshans2k]

• I've read the docs of nestjs-pino
• I've read the docs of pino and pino-http
• I couldn't find the same open issue of nestjs-pino
• This bug is related only to current library or I've tested the same behaviour with the built-in logger and this is not a bug of NestJS.

What is the current behavior?
Using nestjs pino logger in beforeApplicationShutdown and onApplicationShutdown callbacks doesn't log in the stdout. However in onModuleDestroy using logger, logs the event. console.log works in all three callbacks.

What is the expected behavior?
Nestjs pino logger should be available in all three shutdown callbacks.

Please provide minimal example repo, not code snippet. Without example repo this issue will be closed.
https://github.com/dilshans2k/nestjs-pino-issue/tree/feature/pino-test-with-nestjspino4-pino8.18-pinohttp9
In this repo, i have app module, then a nested module inside app module and a provider 'GracefulShutdownEventLogger'. Now what i have seen is if i put a sleep in the provider 'GracefulShutdownEventLogger' in onApplicationShutdown cb (since this provider will be called the last upon application destroy), all other services application shutdown callbacks will be able to log using pino logger, but i don't know why this happens. And why do i need to wait in the 'GracefulShutdownEventLogger'.

Please mention other relevant information such as Node.js version and Operating System.
[email protected] Ubuntu 22.04

[dilshans2k]

I learned that pino uses asynchronous logging, and their docs mention that some buffered logs might get lost on sudden system failure. I get that this can happen if the process receives a SIGKILL, but a SIGTERM or SIGINT is not a sudden failure, so pino should flush the logs properly on those signals. Maybe there is something wrong with my code. Can you please check it?

[iamolegga]

Thanks for reporting this. Unfortunately, I haven't had a chance to check this yet, I will get back to this as soon as possible

[clintonb]

I just came across this issue, too.

[eplightning]

For anyone still struggling with this:

The way enableShutdownHooks handles shutdown doesn't allow pino to close properly.

Workaround is to write your own shutdown hook instead of using the NestJS one:

function closeOnShutdown(app: INestApplicationContext): void {
  let shutdown = false;

  for (const signal of ['SIGTERM', 'SIGQUIT', 'SIGINT']) {
    process.on(signal, async () => {
      if (shutdown) {
        return;
      }
      shutdown = true;

      try {
        await app.close();
        process.exit(0);
      } catch (e) {
        console.error(e);
        process.exit(1);
      }
    });
  }
}

async function bootstrap() {
  const app = await NestFactory.create<NestFastifyApplication>(
    AppModule,
    new FastifyAdapter(),
    {
      bufferLogs: true,
    }
  );
  // ...

  await app.listen(3000);
  closeOnShutdown(app);
}

[thomaschaaf]

I came across the same issue but discovered that it only exists if the log destination is async.

I have created a pull request nestjs/nest#14433 to fix the underlying issue.