Fix: File Transport not flush buffers to file

lib/winston/transports/file.js

@@ -87,6 +87,7 @@ module.exports = class File extends TransportStream {
     this._created = 0;
     this._drain = false;
     this._opening = false;
+    this._destOpened = false;
     this._ending = false;
 
     if (this.dirname) this._createLogDirIfNotExist(this.dirname);
@@ -522,8 +523,8 @@ module.exports = class File extends TransportStream {
    */
   _endStream(callback = () => {}) {
     if (this._dest) {
-      this._stream.unpipe(this._dest);
       this._dest.end(() => {
+        this._stream.unpipe(this._dest);
         this._cleanupStream(this._dest);
         callback();
       });
@@ -532,6 +533,36 @@ module.exports = class File extends TransportStream {
     }
   }
 
+  /**
+   * To fix issue https://github.com/winstonjs/winston/issues/228
+   * @private
+   * @param {function} cb Delaying the 'finish' event until callback is called
+   * @returns {undefined}
+   */
+  _waitStreamsCreatedButNotPiped(cb) {
+    if (this._destOpened) {
+      cb();
+      return;
+    }
+
+    this.once('startPipe', () => {
+      this._dest.once('finish', cb);
+
+      this.close(this._endStream.bind(this));
+    });
+  }
+
+  /**
+   * See https://nodejs.org/api/stream.html#stream_writable_final_callback
+   *
+   * @private
+   * @param {function} cb Call this function (optionally with an error argument) when finished writing any remaining data.
+   * @returns {undefined}
+   */
+  _final(cb) {
+    this._waitStreamsCreatedButNotPiped(cb);
+  }
+
   /**
    * Returns the WritableStream for the active file on this instance. If we
    * should gzip the file then a zlib stream is returned.
@@ -549,8 +580,10 @@ module.exports = class File extends TransportStream {
       .on('close', () => debug('close', dest.path, dest.bytesWritten))
       .on('open', () => {
         debug('file open ok', fullpath);
+        this._destOpened = true;
         this.emit('open', fullpath);
         source.pipe(dest);
+        this.emit('startPipe');
 
         // If rotation occured during the open operation then we immediately
         // start writing to a new PassThrough, begin opening the next file

test/helpers/scripts/logger-end-and-process-exit.js

@@ -0,0 +1,22 @@
+'use strict';
+
+const path = require('path');
+const winston = require('../../../lib/winston');
+
+
+var logger = winston.createLogger({
+  transports: [
+    new winston.transports.File({
+      filename: path.join(__dirname, '..', '..', 'fixtures', 'logs', 'logger-end-and-process-exit.log')
+    })
+  ]
+});
+
+
+logger.on('finish', () => {
+  process.exit(0);
+});
+
+logger.info('CHILL WINSTON!', { seriously: true });
+
+logger.end();

test/transports/file.test.js

@@ -1,5 +1,7 @@
 'use strict';
 
+const os = require('os');
+const { execFile } = require('child_process');
 const path = require('path');
 const winston = require('../../');
 const helpers = require('../helpers');
@@ -13,6 +15,27 @@ function noop() {};
 describe('File({ filename })', function () {
   this.timeout(10 * 1000);
 
+  it('should flush when logger.end() invoked and process.exit immediately', (done) => {
+    const logPath = path.join(__dirname, '../fixtures/logs/logger-end-and-process-exit.log');
+    const scriptPath = path.join(__dirname, '../helpers/scripts/logger-end-and-process-exit.js');
+
+    try {
+      // eslint-disable-next-line no-sync
+      fs.unlinkSync(logPath);
+    } catch (err) {
+      // ignore err
+    }
+
+    execFile('node', [scriptPath], (err) => {
+      if (err) return done(err);
+      fs.readFile(logPath, { encoding: 'utf8' }, (err, content) => {
+        if (err) return done(err);
+        assume(content).equals('{"seriously":true,"level":"info","message":"CHILL WINSTON!"}' + os.EOL);
+        done();
+      });
+    });
+  });
+
   it('should write to the file when logged to with expected object', function (done) {
     var filename = path.join(__dirname, '..', 'fixtures', 'file', 'simple.log');
     var transport = new winston.transports.File({