Crash "Error: ENOENT: no such file or directory"

gigouni commented 6 years ago

Hi,

Expected Behavior

When setting rotation file, it should not crash "randomly".

Current Behavior

Without knowing what happened, the logger crash. I'm using several projects with the same stack, the same Logger module but, when running during the night, some crashed and the other ones are still running (no crash of the logger).

I tried to resolve the problem and found this issue but it seems to be fixed since npm v5.4.1.

Here the report of npm doctor

λ npm doctor
npm WARN verifyCachedFiles Content garbage-collected: 1001 (35181061 bytes)
npm WARN verifyCachedFiles Cache issues have been fixed
Check                               Value                                               Recommendation
npm ping                            OK
npm -v                              v5.6.0                                              Use npm v6.2.0
node -v                             v8.10.0                                             Use node v8.11.3
npm config get registry             https://registry.npmjs.org/
which git                           C:\Users\ngigou\installationFolder\git\cmd\git.EXE
Perms check on cached files         ok
Perms check on global node_modules  ok
Perms check on local node_modules   ok
Verify cache contents               verified 4988 tarballs

Here two examples of the crash of the app:

# some correct logs here...
14:55:06.323Z INFO project_name: Database:: checkAuthToDb:: models synchronized successfully
# some hours later...
events.js:183
throw er; // Unhandled 'error' event
^

Error: ENOENT: no such file or directory, unlink 'C:\Users\ngigou\dev\apps\project_name\logs\project_name-error-2018-07-17.log'
00:00:00.423Z INFO project_name: Server index:: Closing connection with the server...
[nodemon] app crashed - waiting for file changes before starting...

or even (small difference, stat instead of unlink)

# some correct logs here...
14:55:06.323Z INFO project_name: Database:: checkAuthToDb:: models synchronized successfully
# some hours later...
events.js:183
throw er; // Unhandled 'error' event
^

Error: ENOENT: no such file or directory, stat 'C:\Users\ngigou\dev\apps\project_name\logs\project_name-error-2018-07-17.log'
00:00:00.423Z INFO project_name: Server index:: Closing connection with the server...
[nodemon] app crashed - waiting for file changes before starting...

Possible Solution

Could it be a asynchronous issue when trying to rotate files?
Some logs from previous days aren't zipped but some are (the days concerned by the crash), compression issue?
Seen this issue but I really need to have two different files, is it impossible to split streams to different depending on the criticity?

Code

The Logger is imported as a node module (-> parentConfigPath) but can be run locally, without parent project (for dev usage).

import logger from 'my-logger-name'

lib/Logger.js

import bunyan from 'bunyan'
import path from 'path'
import RotatingFileStream from 'bunyan-rotating-file-stream'

const prefix = 'Logger::'
const parentConfigPath = '../../../../config/config'
const localConfigPath = '../../config/config'

class Logger {
  /**
   * @description Construct a Logger.
   * @see https://www.npmjs.com/package/bunyan-rotating-file-stream
   */
  constructor() {
    this.options = this._getConfig()
    this.logger = bunyan.createLogger({
      name: this.options.LOG_FILENAME,
      streams: [
        {
          stream: new RotatingFileStream({
            path: `${this.options.LOG_FOLDER_NAME}/${this.options.LOG_FILENAME}-%Y-%m-%d.log`,
            period: this.options.LOG_PERIOD,
            totalFiles: this.options.LOG_NB_COPIES,
            rotateExisting: this.options.LOG_DAILY_ROTATE,
            threshold: this.options.LOG_MAX_SIZE,
            totalSize: this.options.LOG_TOTAL_SIZE,
            gzip: this.options.LOG_COMPRESS_OLD_LOGS
          }),
          level: this.options.LOG_LEVEL
        },
        {
          stream: new RotatingFileStream({
            path: `${this.options.LOG_FOLDER_NAME}/${this.options.LOG_ERROR_FILENAME}-%Y-%m-%d.log`,
            period: this.options.LOG_PERIOD,
            totalFiles: this.options.LOG_NB_COPIES,
            rotateExisting: this.options.LOG_DAILY_ROTATE,
            threshold: this.options.LOG_MAX_SIZE,
            totalSize: this.options.LOG_TOTAL_SIZE,
            gzip: this.options.LOG_COMPRESS_OLD_LOGS
          }),
          level: this.options.LOG_ERROR_LEVEL
        },
        {
          stream: process.stdout,
          level: this.options.LOG_LEVEL
        }
      ]
    })
  }

  /**
   * @private
   * @description Check if the parent folder of the logger folder is node_modules/ or not.
   * @returns {Boolean} - True if the logger is in node_modules. False otherwise.
   */
  _hasNodeModulesAsParent() {
    const parentFolderName = path.resolve(__dirname, '../../..')
    return parentFolderName.endsWith('node_modules')
  }

  /**
   * @private
   * @description Get the config data.
   * @returns {Object} - The data config caught from config files.
   */
  _getConfig() {
    let config
    if (this._hasNodeModulesAsParent()) {
      config = require(parentConfigPath)
    } else {
      config = require(localConfigPath)
    }
    return config
  }
}

export default new Logger()

config/config.js

  LOG_FOLDER_NAME: process.env.LOG_FOLDER_NAME || 'logs',
  LOG_FILENAME: process.env.LOG_FILENAME || 'project_name',
  LOG_DATE_PATTERN: process.env.LOG_DATE_PATTERN || 'YYYY-MM-DD',
  LOG_LEVEL: process.env.LOG_LEVEL || 'debug',
  LOG_PERIOD: process.env.LOG_PERIOD || '1d',
  LOG_NB_COPIES: process.env.LOG_NB_COPIES || 10,
  LOG_MAX_SIZE: process.env.LOG_MAX_SIZE || '10m',
  LOG_TOTAL_SIZE: process.env.LOG_TOTAL_SIZE || '20m',
  LOG_COMPRESS_OLD_LOGS: process.env.LOG_COMPRESS_OLD_LOGS || true,
  LOG_DAILY_ROTATE: process.env.LOG_DAILY_ROTATE || true,
  LOG_ERROR_FILENAME: process.env.LOG_ERROR_FILENAME || 'project_name-error',
  LOG_ERROR_LEVEL: process.env.LOG_ERROR_LEVEL || 'error',

Context (Environment)

Windows 10 Professional
Version 1709
Version OS: 16299.334
npm: v5.6.0
node: v8.10.0

package-lock.json

    "bunyan": {
      "version": "1.8.12",
      "resolved": "https://registry.npmjs.org/bunyan/-/bunyan-1.8.12.tgz",
      "integrity": "sha1-8VDw9nSKvdcq6uhPBEA74u8RN5c=",
      "requires": {
        "dtrace-provider": "0.8.6",
        "moment": "2.22.1",
        "mv": "2.1.1",
        "safe-json-stringify": "1.1.0"
      }
    },
    "bunyan-rotating-file-stream": {
      "version": "1.6.3",
      "resolved": "https://registry.npmjs.org/bunyan-rotating-file-stream/-/bunyan-rotating-file-stream-1.6.3.tgz",
      "integrity": "sha512-pJFBvosqXjYXsOtDr72SDhZr3d+1ADDBO8TiU0ju0DbNBS4+vjI3GatczzB7LCcBWqWevQ91j1HYsl8cgnI+HQ==",
      "requires": {
        "async": "1.5.2",
        "lodash": "4.17.10",
        "semver": "5.5.0",
        "strftime": "0.9.2"
      }
    },

@Rcomian

Thanks

gigouni commented 6 years ago

Seems to be resolved when using only one file instead of two. Would be better to be able to split streams within different files depending on the log level.

Still waiting to be sure it's fixed. It's not because it didn't crashed yet that it's solved.

gigouni commented 6 years ago

@Rcomian Clues about this issue?

Rcomian / bunyan-rotating-file-stream