bunyan-rotating-file-stream - npm Package Compare versions

Comparing version 1.1.1 to 1.2.0

CHANGES.md

 # bunyan Changelog
 
-Known issues:
+## 1.2.0
 
+- Support non-raw streams. For some reason, raw streams are MUCH faster in high load scenarios (at least when this is the only stream).
+- Better guarantees over file rollover - we will write exactly one log record that goes over the size threshold before we rotate
+  The previous performance release meant that we couldn't rotate until the write had completed to the disk - in the meantime several other
+  logs could have been written. This made everything unpredictable.
+- Making better use of the cargo datatype to write multiple log records in a single event loop tick.
+- Using setImmediate rather than process.nextTick in the write loop to allow io and other operations time to happen rather than hog the event loop.
+
 ## 1.1.1
@@ -6,0 +13,0 @@

lib/filerotator.js

@@ -49,2 +49,3 @@ 'use strict';
     function shutdownCurrentStream(next) {
+        base.emit('closefile');
         stream.end(next);
@@ -51,0 +52,0 @@ stream = null;

lib/limitedqueue.js

@@ -10,3 +10,3 @@ 'use strict';
 
-    const maxQueueLength = 10000;
+    const maxQueueLength = 100000;
     const queueClearingThreshold = 0.8;
@@ -51,3 +51,3 @@ var throwLogsAway = false;
         worker(s, callback);
-    }, 1);
+    }, 2000);
 
@@ -134,2 +134,3 @@ function push(s) {
         resume: queue.resume,
+        unshift: queue.unshift,
         join
@@ -136,0 +137,0 @@ }, base);

lib/nextrotationtime.js

@@ -1,2 +0,2 @@
-"use strict";
+'use strict';
 
@@ -3,0 +3,0 @@ var _DEBUG = false;

lib/rotatingfilestream.js

@@ -34,18 +34,33 @@ // A rotating file stream will just
     var stream = null;
+    var streambytesWritten = 0;
 
     function writer(logs, callback) {
         for (var i = 0; i < logs.length; i += 1) {
-            var str = JSON.stringify(logs[i], bunyan.safeCycles()) + '\n';
+            if (stream) {
 
-            stream.write(str, function (err) {
-                if (err) {
-                    base.emit('error', err);
+                var str;
+                if (typeof (logs[i]) === 'string') {
+                    str = logs[i];
                 } else {
-                    base.emit('data', { bytesWritten: stream.bytesWritten });
+                    str = JSON.stringify(logs[i], bunyan.safeCycles()) + '\n';
                 }
 
-            });
+                var writeBuffer = new Buffer(str, 'utf8');
+
+                stream.write(writeBuffer, function (err) {
+                    if (err) {
+                        base.emit('error', err);
+                    }
+                });
+
+                streambytesWritten += writeBuffer.byteLength;
+                base.emit('data', { bytesWritten: stream.bytesWritten });
+            } else {
+                // We suddenly don't have a stream, save this log for later
+                writeQueue.unshift(logs[i]);
+            }
+
         }
 
-        process.nextTick(function () {
+        setImmediate(function () {
             callback();
@@ -71,4 +86,9 @@ });
 
+    rotator.on('closefile', function () {
+        stream = null;
+    });
+
     rotator.on('newfile', function (newfile) {
         stream = newfile.stream;
+        streambytesWritten = 0;
         base.emit('newfile', { path: newfile.path });
@@ -75,0 +95,0 @@ });

package.json

 {
   "name": "bunyan-rotating-file-stream",
-  "version": "1.1.1",
+  "version": "1.2.0",
   "description": "a rotating file stream for the bunyan logging system",
@@ -5,0 +5,0 @@ "author": "Jim Tupper <[e-mail]> (http://github.com/rcomian)",

README.md

 Bunyan is **a simple and fast JSON logging library** for node.js services:
-Bunyan Rotating File Stream is an improved rotating file stream component that has some extra features
+Bunyan Rotating File Stream is a rotating file stream component that has some extra features
 
 ```js
-    new RotatingFileStream({
-        path: '/var/log/foo.log',
-        period: '1d',   // daily rotation
-        totalFiles: 3   // keep at most 3 back copies
+    var log = bunyan.createLogger({
+        name: 'foo',
+        streams: [{
+            stream: new RotatingFileStream({
+                path: '/var/log/foo.log',
+                period: '1d',          // daily rotation
+                totalFiles: 10,        // keep up to 10 back copies
+                rotateExisting: true,  // Give ourselves a clean file when we start up, based on period
+                threshold: 10m,        // Rotate log files larger than 10 megabytes
+                totalSize: 20m,        // Don't keep more than 20mb of archived log files
+                gzip: true             // Compress the archive log files to save space
+            })
+        }]
     });
 ```
 
+# Recent changes
 
+## 1.2.0
+
+- Support non-raw streams. For some reason, raw streams are MUCH faster in high load scenarios (at least when this is the only stream).
+- Better guarantees over file rollover - we will write exactly one log record that goes over the size threshold before we rotate
+  The previous performance release meant that we couldn't rotate until the write had completed to the disk - in the meantime several other
+  logs could have been written. This made everything unpredictable.
+- Making better use of the cargo datatype to write multiple log records in a single event loop tick.
+- Using setImmediate rather than process.nextTick in the write loop to allow io and other operations time to happen rather than hog the event loop.
+
 # Current Status
@@ -30,3 +49,3 @@
 
-- Rotate to a new log file periodically
+- Rotate to a new log file periodically (can also rotate on startup to clean old log files)
 - Rotate to a new log file once the main log file goes over a certain size
@@ -36,2 +55,3 @@ - Keep a maximum number of archival log files
 - GZip archived log files
+- Supports being a raw stream or a normal stream
 
@@ -41,11 +61,10 @@
 
-**WARNING on node 0.8 usage:** Users of Bunyan's `rotating-file` should (a) be
-using at least bunyan 0.23.1 (with the fix for [this
-issue](https://github.com/trentm/node-bunyan/pull/97)), and (b) should use at
+**WARNING on node 0.8 usage:** Users should use at
 least node 0.10 (node 0.8 does not support the `unref()` method on
-`setTimeout(...)` needed for the mentioned fix). The symptom is that process
-termination will hang for up to a full rotation period.
+`setTimeout(...)`). The symptom is that process
+termination will hang for up to a full rotation period if period rotation is used.
+You can manually keep hold of the logger and call "shutdown" to prevent this.
 
 **WARNING on [cluster](http://nodejs.org/docs/latest/api/all.html#all_cluster)
-usage:** Using Bunyan's `rotating-file` stream with node.js's "cluster" module
+usage:** Using `bunyan-rotating-file-stream` with node.js's "cluster" module
 can result in unexpected file rotation. You must not have multiple processes
@@ -59,17 +78,21 @@ in the cluster logging to the same file path. In other words, you must have
 
-A `type === 'raw'` is a file stream that handles file automatic
-rotation.
+Add this stream directly to the bunyan logger.
+The logger supports being both a raw and normal stream modes. Raw streams can be faster
+under some high-load scenarios but may serialize the json differently to bunyan.
 
 ```js
-var log = bunyan.createLogger({
-    name: 'foo',
-    streams: [{
-        type: 'raw',
-        stream: new RotatingFileStream({
-            path: '/var/log/foo.log',
-            period: '1d',   // daily rotation
-            totalFiles: 3        // keep 3 back copies
-        })
-    }]
-});
+    var log = bunyan.createLogger({
+        name: 'foo',
+        streams: [{
+            stream: new RotatingFileStream({
+                path: '/var/log/foo.log',
+                period: '1d',          // daily rotation
+                totalFiles: 10,        // keep 10 back copies
+                rotateExisting: true,  // Give ourselves a clean file when we start up, based on period
+                threshold: 10m,        // Rotate log files larger than 10 megabytes
+                totalSize: 20m,        // Don't keep more than 20mb of archived log files
+                gzip: true             // Compress the archive log files to save space
+            })
+        }]
+    });
 ```
@@ -80,9 +103,9 @@
 ```sh
-/var/log/foo.log.0     # yesterday
-/var/log/foo.log.1     # 1 day ago
-/var/log/foo.log.2     # 2 days ago
+/var/log/foo.log.1     # yesterday
+/var/log/foo.log.2     # 1 day ago
+/var/log/foo.log.3     # 2 days ago
 ```
 
 *Currently*, there is no support for providing a template for the rotated
-files.
+file names.
 
@@ -119,5 +142,5 @@ <table>
 <td>If period is also set, will rotate an existing log file when the process
-starts up if that file would have been rotated due to its age. This means that
-if you want a new file every day, and the process isn't running overnight,
-when you start up the next day you'll get a new file anyway.</td>
+starts up if that file needs rotating due to its age. This means that
+if you want a new file every day, and the process isn't running over midnight,
+this option will give you that new file when you next startup.</td>
 </tr>
@@ -129,3 +152,3 @@ <tr>
 <td>The maximum size for a log file to reach before it's rotated.
-Can be specified as a number of bytes, or a more friendly unit:
+Can be specified as a number of bytes, or a more friendly units:
 eg, '100k', '1m', '2g' etc.</td>
@@ -137,3 +160,3 @@ </tr>
 <td>0</td>
-<td>The number of rotated files to keep. 0 to keep files regardless of how many there are.</td>
+<td>The maximum number of rotated files to keep. 0 to keep files regardless of how many there are.</td>
 </tr>
@@ -143,3 +166,3 @@ <td>totalSize</td>
 <td>0</td>
-<td>Delete older rotated files once the total size of rotated files reaches this size.
+<td>The maximum storage to allow for the rotated files. Older files are deleted to keep within this size.
 0 here keeps files regardless of how large they get.
@@ -146,0 +169,0 @@ Can be specified as a number of bytes, or a more friendly unit:

test-perf.js

@@ -10,4 +10,10 @@ var bunyan = require('bunyan');
 var InitialPeriodRotateTrigger = require('./lib/initialperiodtrigger');
-var whyRunning = require('why-is-node-running')
+var whyRunning;
 
+try {
+    var whyRunning = require('why-is-node-running');
+} catch (e) {
+    console.log('"Why is node running" disabled');
+}
+
 function runTest(name, options, next) {
@@ -99,2 +105,3 @@ var rfs = RotatingFileStream(_.extend({}, { path: 'foo.log' }, options.stream));
     if (err) console.log(err);
+    clearTimeout(totalTimeout);
 });
@@ -104,5 +111,5 @@
     console.log('Still running: ');
-    whyRunning();
+    if (whyRunning) {
+        whyRunning();
+    }
 }, 40000);
-
-totalTimeout.unref();

test.js

@@ -10,4 +10,10 @@ var bunyan = require('bunyan');
 var InitialPeriodRotateTrigger = require('./lib/initialperiodtrigger');
-var whyRunning = require('why-is-node-running')
+var whyRunning;
 
+try {
+    var whyRunning = require('why-is-node-running');
+} catch (e) {
+    console.log('"Why is node running" disabled');
+}
+
 function runTest(name, options, next) {
@@ -19,3 +25,2 @@ var rfs = RotatingFileStream(_.extend({}, { path: 'foo.log' }, options.stream));
         streams: [{
-            type: 'raw',
             stream: rfs
@@ -33,3 +38,3 @@ }]
     var i = 0;
-    var batch = _.extend({}, { size: 100 }, options.batch);
+    var batch = _.extend({}, { size: 10 }, options.batch);
 
@@ -246,2 +251,4 @@ var ia = setInterval(function () {
     if (err) console.log(err);
+
+    clearTimeout(totalTimeout);
 });
@@ -251,5 +258,5 @@
     console.log('Still running: ');
-    whyRunning();
+    if (whyRunning) {
+        whyRunning();
+    }
 }, 20000);
-
-totalTimeout.unref();

No alert changes

Improved metrics

Total package byte prevSize

57480705

increased by105675.84%

Number of package files

34

increased by47.83%

Lines of code

1058

increased by3.02%

Number of lines in readme file

206

increased by12.57%

No dependency changes