Node-bunyan: Error: ENOENT with Bunyan rotating-file logging

[medric]

Hi,

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"    : "gplanning2014",
    "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.

[trentm]

@medric If you try with an absolute path, does that make a difference?

Either way, certainly Bunyan shouldn't crash here.

[DJWassink]

I have ben experiencing the same issue. Here it seems like to happen every time at midnight when it is supposed to rotate the file.

      {
        name: name,
        src: isDevMode,
        streams: [{
          stream: isDevMode ? prettyStdOut : process.stdout,
        }, {
          type: 'rotating-file',
          path: './logs/log.log',
          period: '1d',
          count: 7
        }, {
          stream: logSchema
        }]
      });

I have been trying to reproduce the error by setting the clock in windows to midnight but it just keeps working without rotating the file. Guess there is something more going on behind the curtains?

Anyhow I will try to check if a absolute path is going to make any difference.

-----EDIT------

Clearly the rotating file only will change after the give time so I changed it to a couple of ms to speed it up.

This time I used a absolute path. As you can see it tried to rename log.log to log.log.0. It correctly renamed the file but somehow still triggered a error?

[DJWassink]

Okay so I dug a little deeper in the problem and made a new clean project to see if the problem was also there. Everything worked fine.

The issue was completely my fault because I made my own module that returned a new Bunyan instance. When this module was used on multiple places each place got it's own Bunyan instance to the same file. Thus multiple loggers logging to the same file. I rewrote my module to only create a Bunyan instance on startup and return that instance.

[sabrehagen]

Thank you for commenting your findings, I believe I am encountering the same issue and your results have helped me!

[cjMdGit]

@DJWassink How did you return a new Bunyan instance before? I am not sure if I have the same issue. I instantiate my logger in a local file utils.js, and require it in several other files. Is a new Bunyan instance is created every time when the utils.js is required in other files? Thanks in advance!

[adebree]

Experiencing that same behaviour here, but I am sure that only a single instance Bunyan instance is created. I create an instance in a module which is exported, due to CommonJS' module implementation only a single execution of the module takes place. But still having the ENOENT when rotating on midnight. But not every midnight...

[sabrehagen]

This error seems to be that the number of open file handles to the log file exceeds the filesystem's set maximum, if that helps anybody.

On 20 Jul 2015, at 7:37 pm, Arne de Bree [email protected] wrote:

Experiencing that same behaviour here, but I am sure that only a single instance Bunyan instance is created. I create an instance in a module which is exported, due to CommonJS' module implementation only a single execution of the module takes place. But still having the ENOENT when rotating on midnight. But not every midnight...

—
Reply to this email directly or view it on GitHub.

[borisdiakur]

Having the same issue. Only one logger instance with a stream of type 'rotating-file'. Using absolute path. Getting Error: ENOENT, open 'logs/my.log'.

[doomsbuster]

@borisdiakur I am using a single logger in one node module and i am receiving the same error

events.js:141
      throw er; // Unhandled 'error' event
      ^

Error: ENOENT: no such file or directory, open '../logs/site.log'
    at Error (native)

Any help is appreciated.

[cjMdGit]

do you have the directory ../logs that exists already?

---

From: Ashish Desai [email protected]
Sent: Saturday, December 26, 2015 4:19 PM
To: trentm/node-bunyan
Cc: cjMdGit
Subject: Re: [node-bunyan] Error: ENOENT with Bunyan rotating-file logging (#235)

@borisdiakurhttps://github.com/borisdiakur I am using a single logger in one node module and i am receiving the same error

[https://avatars3.githubusercontent.com/u/527049?v=3&s=400]https://github.com/borisdiakur

borisdiakur (Boris Diakur) · GitHubhttps://github.com/borisdiakur
github.com
borisdiakur has 12 repositories written in JavaScript, HTML, and Java. Follow their code on GitHub.

events.js:141
throw er; // Unhandled 'error' event
^

Error: ENOENT: no such file or directory, open '../logs/site.log'
at Error (native)

Any help is appreciated.

Reply to this email directly or view it on GitHubhttps://github.com/trentm/node-bunyan/issues/235#issuecomment-167363951.

[doomsbuster]

I figured this one out. bunyan runs from the root of the nodejs application. I set it to logs/site.log and it worked fine. Additionally, I saw it in the CLI documentation that you can pretty format the logs using the command site.log | bunyan which did not work. I had to use bunyan site.log to pretty format it.

[Rcomian]

This appears to be a very common mistake. We can't do much at the moment when working between processes, but when creating multiple rotators in the same process, we can detect that.

My 3rd party rotating file stream will detect that you're trying to do this and fail with an error immediately so you know what's wrong.

https://www.npmjs.com/package/bunyan-rotating-file-stream

[trentm]

Sorry for the delays. Sounds like there have been three issues here:

1. Instantiating multiple Bunyan loggers all trying to rotate to the same file. Granted Bunyan doesn't catch that. I'd be curious what a change to Bunyan would look like to trap that. Also, perhaps suggested improvements to docs could help here.
2. Specifying a log dir that doesn't exist (the 'rotating-file' stream doesn't create the rotation dir for you, intentionally). If a relative path is used, then the error message isn't helpful. I'd be happy with a PR that made the paths absolute and used those, so that error messages would include the full path.
3. Possibly something else in @adebree's example (judging from @sabrehagen's followup). We'd need more details to know there.

I think separate issues should be opened for any follow ups on more specific issues.

[tomalex0]

I'm facing same issue, this is how is setup bunyan logger

App is currently running in cluster mode.

What might be causing the issue, is it the path or cluster mode?

Error: ENOENT, rename '../log/app.log.1'

logger.js

var bunyan = require('bunyan');


var log = bunyan.createLogger({
    name: 'intranet',
    streams: [{
        type: 'rotating-file',
        path: '../log/app.log',
        period: '1d',   // daily rotation
        count: 3        // keep 3 back copies
    }]
});
module.exports=log;

sample.js

var log = require('../lib/logger');

log.info("logme");

sample2.js

var log = require('../lib/logger');

log.info("logme2");

[kamal-mann]

@tomalex0 , checkout this