winston-cloudwatch icon indicating copy to clipboard operation
winston-cloudwatch copied to clipboard

Process may hang unless kthxbye is called twice

Open terrisgit opened this issue 4 years ago • 4 comments

  1. A WinstonCloudWatch transport is configured to handle uncaught exceptions
  2. An unhandled exception occurs immediately before closing the logger via the kthxbye method. Here's one way to throw an unhandled exception:
setTimeout(()=>{throw new Error();}, 1);
  1. While closing the logger, Winston calls add() on the CloudWatch transport with the log entry for the unhandled exception, turning on the transport's background queue processor
  2. The process will hang instead of exiting due to the transport's queue processor

terrisgit avatar Apr 18 '20 16:04 terrisgit

The method for avoiding the hang is:

  1. Call kthxbye() on the CloudWatch transport
  2. Close the logger in exactly the right way
  3. Call kthxbye() again on the CloudWatch transport
// This array should contain WinstonCloudWatch objects. Search issues herein for
// 'kthxbye'  to locate code that finds these transports via winston.loggers
const transports = [];

// Flush CloudWatch transports; otherwise, the logger's finish handler will not fire
// if an error occurred earlier while sending data to CloudWatch (test this by
// disconnecting from the Internet)
await Promise.all(transports.map(transport=>new Promise(resolve => {
  // @todo: Fix this when WinstonCloudWatch makes this an option
  transport.flushTimeout = Date.now()+30000; // 30 seconds
  transport.kthxbye(
    error => {
      if (error) console.error(error);
      resolve();
    });
})));

// Close loggers
await Promise.all(winston.loggers.map(logger => new Promise(resolve => {
  logger.on('finish', ()=>{logger.close(); resolve();});
  logger.end();
})));

// Flush CloudWatch transports again because unhandled exceptions are sent to 
// transports while closing the loggers
await Promise.all(transports.map(transport=>new Promise(resolve => {
  // @todo: Fix this when WinstonCloudWatch makes this an option
  transport.flushTimeout = Date.now()+30000; // 30 seconds
  transport.kthxbye(
    error => {
      if (error) console.error(error);
      resolve();
    });
})));

terrisgit avatar Apr 18 '20 20:04 terrisgit

Thanks for the detailed report.

I will reopen this, and either improve our README or fix the bug.

lazywithclass avatar Apr 19 '20 20:04 lazywithclass

See also https://github.com/winstonjs/winston/issues/1250#issuecomment-622969996

terrisgit avatar May 02 '20 15:05 terrisgit

Just wanted to check whether a fix is applied. I am using 6.1.1 version

nairrajeev avatar Apr 16 '23 23:04 nairrajeev