trentm / node-bunyan

a simple and fast JSON logging module for node.js services
Other
7.17k stars 516 forks source link

Error with 'rotating-file' type logger on rotation #374

Open nibblesnbits opened 8 years ago

nibblesnbits commented 8 years ago

I have an application with the following bunyan configuration:

bunyan.createLogger({
    name: "my-application",
    streams: [{
            level: "error",
            type: "rotating-file",
            path: path.join(dir, "/daily.log"),
            period: "1d",
            count: 7
        }]
});

This works just fine during normal operation, but every time the rotation starts I get the following error:

Error: ENOENT: no such file or directory, rename 'logs/daily.log.3' -> 'logs/daily.log.4'
at Error (native)

It seems that bunyan is having trouble creating the new log file. The odd thing is that the file does end up getting created, but only after the application has restarted. Is there an issue with my configuration, or is this something I can help fix?

timbru31 commented 8 years ago

This issue is also happening with our setup, a fix would be greatly appreciated. Here's the relevant snippet of our config if it helps

    streams = [{
        type: 'rotating-file',
        path: 'server.log',
        period: '4h',
        count: 6
    }];
TekSiDoT commented 8 years ago

I can confirm this behavior, currently using the following configuration:

    this.log = bunyan.createLogger({
        name: 'log',
        level: this.lvl,
        streams: [{
            type: 'rotating-file',
            path: './logs/log.log',
            period: '1h',   
            count: 24
        }]
    });  
Rcomian commented 8 years ago

Could I point you to: https://www.npmjs.com/package/bunyan-rotating-file-stream

I'm starting to get some confidence in this and would really appreciate any feedback. My aim is to make this the definitive file rotation module for bunyan.

Certainly the issue in this configuration needs to be fixed. But in the meantime, this module should support your needs.

kamal-mann commented 8 years ago

I was having the same issue and what I found was in my code there were lots of other modules calling to bunyan.createLogger(). It worked for me with following change in my Bunyan log provider:

var MYINSTANCE = null;
function getLogger(moduleName)
{
  if (!MYINSTANCE || null === MYINSTANCE) {

      MYINSTANCE = bunyan.createLogger({name: "myAppName-"+moduleName, src:true, level:'TRACE',
            streams: [
              {
                type: 'rotating-file',
                level: 'trace',
                path: 'logs/hereICome.log', 
                period: "60000ms",
                count: 5
              }
          ]
      });
  }
  return MYINSTANCE;
}
jcollum commented 7 years ago

Happening to me as well. Only one call to createLogger, so that's not it.

The error:

Error: ENOENT: no such file or directory, rename '/var/log/cdk/dbUtils/warn.log.11' -> '/var/log/cdk/dbUtils/warn.log.12'
    at Error (native)
Uncaught exception!
{ '0': 
   { Error: ENOENT: no such file or directory, rename '/var/log/cdk/dbUtils/warn.log.11' -> '/var/log/cdk/dbUtils/warn.log.12'
       at Error (native)
     errno: -2,
     code: 'ENOENT',
     syscall: 'rename',
     path: '/var/log/cdk/dbUtils/warn.log.11',
     dest: '/var/log/cdk/dbUtils/warn.log.12' } }

Streams config:

loggerStreams = [
  {
    level: config.logging.console.level
    stream: process.stdout
  }, {
    level: bunyan.WARN,
    type: 'rotating-file',
    period: '12h', # 12 hour rotation
    count: 14
    path: ((require('path')).join('/var', 'log', 'cdk', 'dbUtils', 'warn.log'))
  }
]

Access rights to the stream dir:

$ ls -alh /var/log/cdk/
total 12K
drwxrwxrwx   3 root node_apps  4.0K Oct 20 18:13 .
drwxr-xr-x. 16 root dsunixuser 4.0K Oct 30 03:16 ..
drwxrwxrwx   2 root node_apps  4.0K Oct 31 22:00 dbUtils

Versions:

$ node --version
v6.5.0

$ cat  /etc/centos-release
CentOS Linux release 7.1 (Core

$ pm2 --version
2.0.18

$ ./node_modules/.bin/bunyan --version
bunyan 1.8.4

This is causing my API to die on production every time the log rotates! OK it's clustered so it's not that big of a deal but still: do not like. Turning off file-based log rotation until further notice.

jcollum commented 7 years ago

I thought this might be because I had two instances of my API running. So I killed the second instance and restarted. Still seeing a crash due to log rotation:

Error: ENOENT: no such file or directory, rename '/var/log/cdk/dbUtils/warn.log.1' -> '/var/log/cdk/dbUtils/warn.log.2'
    at Error (native)
csreddy commented 7 years ago

I'm facing the same issue. Happens everyday during log rotation, sometimes it crashes the app even in cluster mode. Weirdly the process runners (pm2/forever) do not even know that the app has crashed, so I have to manually restart the app.

ethan-hunt-007 commented 7 years ago

having the same while log rotation... please suggest some fix.

csreddy commented 7 years ago

I ended up moving log rotation to linux logrotate utility Here's the config I used in case you're interested.

Rotates logs every day and retains for 7 days config location: /etc/logrotate.d/myapp

/space/myapp/logs/*log {
    daily
    rotate 7
    missingok
    copytruncate
    notifempty
    delaycompress
    postrotate
        # for debugging
         mail -s "Logs rotated at $(date)" username@email.com < /dev/null
    endscript
}
ethan-hunt-007 commented 7 years ago

I avoided thing issue using static method for logger and it worked in my case:

 function Logger(name, clazz) {
    this.clazz = clazz;
    if(!Logger.app) {
        Logger.app = name;
        Logger.init();
    }
}

Logger.init = function() {
    var bunyan = require('bunyan');
    Logger.logger = bunyan.createLogger({
        name: Logger.app,
        streams: [{
            // stream : process.stdout
            type: 'rotating-file',
            path: __dirname + '/../logs/' + Logger.app + "-info.log",
            period: '6h',
            count: 4
        }]
    });
}

Logger.prototype.info = function(log) {
    Logger.logger.info(`[${this.clazz}]: ${log}`);
}

Logger.prototype.warn = function(log) {
    Logger.logger.warn(`[${this.clazz}]: ${log}`);
}

Logger.prototype.error = function(log) {
    Logger.logger.error(`[${this.clazz}]: ${log}`);
}

module.exports = Logger;

Here the arguments are :-- name : the app name which would be general for all modules clazz : the current module for writing logs

In this way the initialization would be only once.

Using below line in every module one can initialize a logger: var logger = new (require('logger'))(<APP_NAME>, <MOD_NAME>);

scippio commented 7 years ago

Still living bug:

app            | /usr/src/app/node_modules/pipeworks/pipeworks.js:208
app            |         throw err; // rethrow;
app            |         ^
app            | 
app            | Error: ENOENT: no such file or directory, rename '/usr/src/app/logs/app.log' -> '/usr/src/app/logs/app.log.0'

My init:

this.log = Bunyan.createLogger({
            name: "Log",
            level: this.logLevel,
            streams: [{
                stream: process.stderr
            },{
                type: 'rotating-file',
                path: `${appRoot}/logs/app.log`,
                period: '1d',
                count: 3
            }]
        })
Borkes commented 6 years ago

I am facing the same issue. Here's my config, our application starts two instances with pm2 cluster, and share logPath with another process.

const bunyanLog = bunyan.createLogger({
    name: 'casino',
    level: 'info',
    streams: [{
        type: 'rotating-file',
        path: logPath,  ///var/log/texas/clog.txt
        period: '1d',
        count: 10
    }]
});

there is three instances (two apps) use the same logPath.

    |  40  │ fork     │ 4712  │ online │ 
   │ 68 │ cluster │ 5614  │ online │  
   │ 69 │ cluster │ 5619  │ online  |
Rcomian commented 6 years ago

@Borkes unfortunately the logging just can't work with more than one process talking to the same path.

There's no good solution to this except using different log files for each process. Perhaps insert the PID into the filename, or host+pid if logging from multiple hosts.

masterjaso commented 6 years ago

For my use case, I utilize the cluster.worker.id in the file name to setup logs for the different worker threads. Sadly, the error still persists on log rotation - but not every time... Not sure what the issue is...

zhouw commented 6 years ago

I also encountered this problem when I created a new logger in each module. The use case is that I need to save module name to the log. To resolve this problem, I created a singleton logger in global, then created child logger for each module. The code would look like this:

module.exports = function(module) {
    if (!global._logger) {
        global._logger = bunyan.createLogger({
            streams: [
                {
                    level: 'info',
                    type: 'rotating-file',
                    path: './logs/' + process.env.NODE_ENV + '.log',
                    period: '1d',   // daily rotation
                    count: 5        // keep 3 back copies
                }
            ]
        });
    }

    let ch = module.filename.includes('\\') ? '\\' : '/';
    let filename = module.filename.split(ch).slice(-1);
    if (filename && filename.length == 1) {
        filename = filename[0].split('.')[0];
    }

    return global._logger.child({
            module: filename
        });
};
th3nate commented 6 years ago

in my case creating a singleton logger and making sure i have the logger files already created in the logs folder.

if your config is like this for example:

bunyan.createLogger({ streams: [ { level: 'info', type: 'rotating-file', path: './logs/combined.log', period: '1d', // daily rotation count: 3 // keep 3 back copies } ] });

that means that bunyan is going to require 4 files (count property):

combined.log | combined.log.0 | combined.log.1 | combined.log.2

just make sure these files are available when your app initialized and you're good to go.

cchandurkar commented 3 years ago

Almost end of 2020, still facing this. Any solution so far?

brunoracosta commented 3 years ago

The something is happing with me. Any solution?

I found a way to turn around this problem.

In my case, the problem was that I am using lerna so the project that start bunyan is in packages/localServer/lib. So I alter the path for path.join(__dirname, '../../../', 'logs/audit.log');

trupti-shetty commented 3 years ago

I am not sure if this will help. But I was getting this error because the file name had some special characters & the file was failing to create. After removing it worked. Bunyan Version used - 1.8.12 logger.js:

const bunyan = require('bunyan');
var log = bunyan.createLogger({
    name: 'AppName',
    streams: [{
        level: 'info',
        path: rootPath + '/app-info.log'
    },
    {
        level: 'error',
        path: rootPath + '/app-error.log'
    }
    ]
});

var logrotate = require('logrotator');

// use the global rotator
var rotator = logrotate.rotator;

// or create a new instance
// var rotator = logrotate.create();

// check file rotation every 5 minutes, and rotate the file if its size exceeds 10 mb.
// keep only 3 rotated files and compress (gzip) them.
rotator.register(rootPath + '/app-info.log', {
  schedule: '1m', 
  size: '10m', 
  compress: true, 
  count: 3, 
  format: function(index) {
    var d = new Date();
    return d.getDate()+"-"+d.getMonth()+"-"+d.getFullYear()+"-"+d.getTime();
  }
});
rotator.register(rootPath + '/app-error.log', {
  schedule: '1m', 
  size: '10m', 
  compress: true, 
  count: 3, 
  format: function(index) {
    var d = new Date();
    return d.getDate()+"-"+d.getMonth()+"-"+d.getFullYear()+"-"+d.getTime();
  }
});
module.exports = log

app.js

const logger = require(path.join(rootPath, 'logger'));
logger.info("log data");