Error: ENOENT with Bunyan rotating-file logging (NodeJS)

Question

I am using the Bunyan module for NodeJS logging. When I try using the rotating-file type, it makes my app crash every time and outputs this error:

Error: ENOENT, rename 'logs/info.log.3'

However, it never happens at the same time so I can't find any logic... This is how I instanciate my logger:

var log = Bunyan.createLogger(config.log.config);
log.info('App started, ' + process.env.NODE_ENV);

And here is my config.json:

  {
    "name"    : "app",
    "streams" : [
        {
            "type"  : "rotating-file",
            "period": "5000ms",        //Low period is for testing purposes
            "count" : 12,
            "level" : "info",
            "path"  : "logs/info.log"
        },
        {
            "type"  : "rotating-file",
            "period": "5000ms",
            "count" : 12,
            "level" : "error",
            "path"  : "logs/error.log"
        },
        {
            "type"  : "rotating-file",
            "period": "5000ms",
            "count" : 12,
            "level" : "trace",
            "path"  : "logs/trace.log"
        }
    ]
  }

Can anyone advise how to fix my issue? Thanks in advance.

Are you using [node.js cluster](https://nodejs.org/api/cluster.html)? — victorkt, Mar 20 '15 at 11:33

score 1 · Answer 1 · answered Dec 16 '15 at 18:37

What I have just done (last night actually) to get around this problem of a master + workers contending over a Bunyan rotating-file is to have the workers write "raw" log records to a stream-like object I created called a WorkerStream. The write method of the WorkerStream simply calls process.send to use IPC to deliver the log record to the master. The master uses a different logger config that points to a rotating-file. The master uses the code shown below to listen for log records from its workers and write them to the log file. So far it appears to be working perfectly.

cluster.on('online', function (worker) {
  // New worker has come online.
  worker.on('message', function (msg) {
    /* Watch for log records from this worker and write them 
       to the real rotating log file.
    */
    if (msg.level) {
      log._emit(msg);
    }
  });
});

score 1 · Answer 2 · answered Mar 27 '16 at 12:29

ln is your friend.

Existing logging libraries have rotation problem with cluster module. Why doesn't ln have this issue?

Both bunyan and log4js rename the log file on rotation. The disaster happens on file renaming under cluster environment because of double files renaming. bunyan suggests using the process id as a part of the filename to tackle this issue. However, this will generate too many files.

log4js provides a multiprocess appender and lets master log everything. However, this must have the bottleneck issue.

To solve this, I just use fs.createWriteStream(name, {"flags": "a"}) to create a formatted log file at the beginning instead of fs.rename at the end. I tested this approach with millisecond rotation under cluster environment and no disasters occurred.

score 0 · Accepted Answer · answered May 05 '15 at 01:20

0

I have experienced the same issue without using clustering. I believe the problem is being caused by old files sitting in the log directory. While the main logger can open and append to existing files, the file rotation logic uses rename, which files when it steps on an existing file. (e.g. an existing info.log.3 file).

I'm still digging into the source to figure out what needs to be changed to recover from the rolling error.

One additional thought as I review the source. If you have multiple Bunyan log instances that use the same log file (in my case, a common error.log), the rename calls could be happening nearly concurrently from the OS level (asynchronous and separate calls from a Node.js perspective, but concurrently from the OS perspective).

answered May 05 '15 at 01:20

Jim Rush

4,143
3
25
27

I also tried digging into the source file, the rename appears on line 1307 on lib/bunyan.js in the moves() function. But I don't think that old files are causing any problem. Actually I found out I was using different instances of the same logger, so I rewrote my logger as a unique angular service that I require in my other files. – Limezest May 06 '15 at 12:08
Better late than never : I was actually returning a new instance every time i called my logger. This was the source of my problem since several instances were accessing the file. – Limezest Jul 24 '15 at 09:13

score 0 · Answer 4 · answered Feb 21 '16 at 22:54

It's sadly not possible to use multiple rotating file streams against the same file.

If you're in the same process, you must use a single logger object - make sure you're not creating multiple of them.

If you're working across processes, you must log to different files. Unfortunately there's nothing yet that has the IPC in place to allow different rotators to coordinate amongst themselves.

I have a plugin rotating file stream that detects if you try to create 2 rotators against the same file in the a single process and throws an error. It can't help in the case of multiple processes tho.

bunyan-rotating-file-stream

score 0 · Answer 5 · answered Jan 25 '21 at 22:32

From my experience, it happens sometimes when the logs directory (or whatever you named it) does not exist.

If you are running through this error in a automation pipeline, for example, you may be ignoring all the files in logs and committing it empty, then it is not created when the repository is cloned by the pipeline.

Simply make sure that logs is created by placing a .gitkeep file inside it (or any other trick).

This may be the case of many of you who come across this question.

Error: ENOENT with Bunyan rotating-file logging (NodeJS)

5 Answers5