DEV Community

Roman Khegay
Roman Khegay

Posted on

My NestJS app "hung" on startup and printed nothing - it was dead all along

Few months ago I started one of my Nest services in watch mode and got... nothing. No error, no "Nest application successfully started", no stack. Terminal just sat there after "Watching for file changes". I was sure something hung on startup and spent good amount of time looking for deadlock that did not exist

Real reason: Redis was not running (I forgot to start docker), and app was not hanging at all. It died in about half second and took all its logs with it

Setup

Pretty standard one, mostly from docs:

  • Nest + Fastify
  • nestjs-pino with bufferLogs: true and app.useLogger(app.get(Logger))
  • Redis client created in module factory, with connection check
  • nest start --watch for local dev

Redis factory looked roughly like this:

{
  provide: REDIS,
  inject: [ConfigService],
  useFactory: async (config: ConfigService) => {
    const redis = new Redis(config.getOrThrow('REDIS_URL'), { lazyConnect: true });
    redis.on('error', () => {}); // errors handled below
    try {
      await redis.connect();
    } catch (error) {
      logger.error(`Failed to connect to ${config.get('REDIS_URL')}`, error);
      process.exit(1);
    }
    return redis;
  },
}
Enter fullscreen mode Exit fullscreen mode

What actually happened

Three things together:

  1. With docker off, host resolves to localhost and connection is refused right away. connect() rejects in about 2 ms
  2. bufferLogs: true keeps every log line in memory until app is ready, so pino logger from DI can print them in its format. My logger.error went into that buffer too
  3. process.exit(1) killed process before anything flushed buffer. Zero lines printed

And then nest start --watch does not say anything when app exits on its own. It just keeps watching files. So silent exit looks exactly like hang

Where buffer is flushed (and where it is not)

I checked this on Nest 11 and 12. Buffered logs are printed:

  • after successful init() (12.1.1+) or in listen() callback
  • when something throws while Nest builds modules, async factories included - exceptions zone flushes before exiting
  • since Nest 12.1.3, when init() rejects, for example async onModuleInit throws

They are not printed:

  • when factory calls process.exit() itself - Nest has no exit hook, so buffer dies with process. One process.on('exit', () => Logger.flush()) in main.ts would have printed my case
  • when onModuleInit never settles (db client retrying forever) - buffer waits for init() to finish, so nothing that goes through Nest Logger shows up. Only what client itself writes to console gets through
  • when you stop such hung app with Ctrl+C - buffer is just dropped

Before 12.1.3 failed onModuleInit also lost every buffered line. Error itself still reached .catch() in main.ts, but if that catch logged through Nest Logger, its line went into buffer too and nothing was printed at all. I had exactly that catch in my code for few weeks

Docs said "If initialization fails, Nest flushes it right away", which was true only for module building. My fix for that is nestjs/nest#18111, it shipped in Nest 12.1.3

Docs now say wich startup failures buffer cannot report: nestjs/docs.nestjs.com#3611

And small one to Nest CLI, so watch mode prints line when app exits instead of staying silent: nestjs/nest-cli#3623, still in review

What I do now

1. Logger exists before Nest does. Instead of buffering, I create pino-based logger myself and pass it to NestFactory.create. Every line goes out immediately, including ones from module factories:

async function bootstrap(): Promise<void> {
  const logger = createLogger({ service: 'matchmaker' }); // LoggerService on top of pino, no DI

  const app = await NestFactory.create(AppModule, new FastifyAdapter(), {
    logger,
    abortOnError: false,
  });

  app.enableShutdownHooks();
  await app.listen(3000, '0.0.0.0');
}

bootstrap().catch((error) => {
  console.error(error);
  process.exit(1); // exitCode alone is not enough if some client still holds event loop
});
Enter fullscreen mode Exit fullscreen mode

Nest prints module building errors with that logger either way. abortOnError: false only makes it rethrow instead of calling process.exit(1) itself, so error also reaches .catch(), where you can alert or clean up before exit. For failing onModuleInit Nest does not log error at all, so .catch() is only place where it shows up. And nothing here is bufered

2. Throw, don't exit. Factory that throws goes through Nest exception handling and gets printed. Factory that calls process.exit() decides for Nest that nobody needs to know why

useFactory: async (config: ConfigService) => {
  const redis = new Redis(config.getOrThrow('REDIS_URL'), {
    lazyConnect: true,
    enableOfflineQueue: false,
  });
  try {
    await redis.connect();
  } catch (error) {
    redis.disconnect(); // otherwise client keeps reconnecting in background
    throw error; // Nest prints it, buffer or not
  }
  return redis;
},
Enter fullscreen mode Exit fullscreen mode

disconnect() matters: rejected connect() does not stop ioredis, it keeps reconnecting, and with abortOnError: false that timer keeps process alive forever

enableOfflineQueue: false matters too: with offline queue on, any command before connection just waits, so await redis.get() in onModuleInit sits there until retries run out (about 10 seconds with ioredis 5 defaults, more than minute on ioredis 6), and forever with maxRetriesPerRequest: null

3. Know which clients lie about connecting. Prisma with MongoDB resolves $connect() even when database is down, first real query then waits for server selection timeout (30 seconds by default). If you rely on $connect() as health check, it will not tell you anything there

Short version

  • bufferLogs + process.exit() in factory = zero output
  • bufferLogs + onModuleInit that never settles = nothing from Nest Logger, also on 12.1.3
  • bufferLogs + failing onModuleInit + .catch() logging through Nest Logger = zero output before 12.1.3
  • nest start --watch stays quiet when app dies
  • create logger before NestFactory.create, throw instead of exit, disconnect client that failed

Hope it saves someone hour or two of looking for hang that is not there

Top comments (0)