bunyan - npm Package Compare versions

Comparing version 0.14.6 to 0.15.0

CHANGES.md

 # bunyan Changelog
 
+## bunyan 0.15.0
+
+- issue #48: Dtrace support! The elevator pitch is you can watch all logging
+  from all Bunyan-using process with this:
+
+        dtrace -x strsize=4k -qn 'bunyan*:::log-*{printf("%d: %s: %s", pid, probefunc, copyinstr(arg0))}'
+
+  Or get the bunyan CLI to render those:
+
+        dtrace -x strsize=4k -qn 'bunyan*:::log-*{printf("%s", copyinstr(arg0))}' | bunyan
+
+  See <https://github.com/trentm/node-bunyan#dtrace-support> for details. By
+  Bryan Cantrill.
+
+
 ## bunyan 0.14.6
@@ -20,4 +35,4 @@
 
-- Improve the crash message to make it easier to provide relevant details in a
-  bug report.
+- Improve the Bunyan CLI crash message to make it easier to provide relevant
+  details in a bug report.
 
@@ -24,0 +39,0 @@

lib/bunyan.js

@@ -7,3 +7,3 @@ /*
 
-var VERSION = '0.14.6';
+var VERSION = '0.15.0';
 
@@ -29,2 +29,7 @@ // Bunyan log format version. This becomes the 'v' field on all log records.
 var assert = require('assert');
+try {
+  var dtrace = require('trentm-dtrace-provider');
+} catch (e) {
+  dtrace = null;
+}
 var EventEmitter = require('events').EventEmitter;
@@ -52,3 +57,3 @@
 if (!format) {
-  // If not node 0.6, then use its `util.format`:
+  // If node < 0.6, then use its `util.format`:
   // <https://github.com/joyent/node/blob/master/lib/util.js#L22>:
@@ -162,2 +167,5 @@ var inspect = util.inspect;
 
+// Dtrace probes.
+var dtp = undefined;
+var probes = dtrace && {};
 
@@ -306,2 +314,18 @@ /**
 
+  if (!dtp && dtrace) {
+    dtp = dtrace.createDTraceProvider('bunyan');
+
+    for (var level in levelFromName) {
+      var probe;
+
+      probes[levelFromName[level]] = probe =
+        dtp.addProbe('log-' + level, 'char *');
+
+      // Explicitly add a reference to dtp to prevent it from being GC'd
+      probe.dtp = dtp;
+    }
+
+    dtp.enable();
+  }
+
   // Helpers
@@ -649,28 +673,8 @@ function addStream(s) {
  * @param rec {log record}
+ * @param noemit {Boolean} Optional. Set to true to skip emission
+ *      and just return the JSON string.
  */
-Logger.prototype._emit = function (rec) {
+Logger.prototype._emit = function (rec, noemit) {
   var i;
 
-  var obj = objCopy(rec[0]);
-  var level = obj.level = rec[2];
-  var recFields = rec[1];
-  if (recFields) {
-    if (this.serializers) {
-      this._applySerializers(recFields);
-    }
-    Object.keys(recFields).forEach(function (k) {
-      obj[k] = recFields[k];
-    });
-  }
-  xxx('Record:', rec)
-  obj.msg = format.apply(this, rec[3]);
-  if (!obj.time) {
-    obj.time = (new Date());
-  }
-  // Get call source info
-  if (this.src && !obj.src) {
-    obj.src = getCaller3Info()
-  }
-  obj.v = LOG_VERSION;
-
   // Lazily determine if this Logger has non-"raw" streams. If there are
@@ -690,6 +694,10 @@ // any, then we need to stringify the log record.
   var str;
-  if (this.haveNonRawStreams) {
-    str = JSON.stringify(obj, safeCycles()) + '\n';
+  if (noemit || this.haveNonRawStreams) {
+    str = JSON.stringify(rec, safeCycles()) + '\n';
   }
 
+  if (noemit)
+    return str;
+
+  var level = rec.level;
   for (i = 0; i < this.streams.length; i++) {
@@ -699,6 +707,8 @@ var s = this.streams[i];
       xxx('writing log rec "%s" to "%s" stream (%d <= %d): %j',
-        obj.msg, s.type, s.level, level, obj);
-      s.stream.write(s.raw ? obj : str);
+        rec.msg, s.type, s.level, level, rec);
+      s.stream.write(s.raw ? rec : str);
     }
   };
+
+  return str;
 }
@@ -713,29 +723,68 @@
   return function () {
-    var fields = null, msgArgs = null;
+    var log = this;
+
+    function mkRecord(args) {
+      if (args[0] instanceof Error) {
+        // `log.<level>(err, ...)`
+        fields = {err: errSerializer(args[0])};
+        if (args.length === 1) {
+          msgArgs = [fields.err.message];
+        } else {
+          msgArgs = Array.prototype.slice.call(args, 1);
+        }
+      } else if (typeof (args[0]) === 'string') {  // `log.<level>(msg, ...)`
+        fields = null;
+        msgArgs = Array.prototype.slice.call(args);
+      } else if (Buffer.isBuffer(args[0])) {  // `log.<level>(buf, ...)`
+        // Almost certainly an error, show `inspect(buf)`. See bunyan issue #35.
+        fields = null;
+        msgArgs = Array.prototype.slice.call(args);
+        msgArgs[0] = util.inspect(msgArgs[0]);
+      } else {  // `log.<level>(fields, msg, ...)`
+        fields = args[0];
+        msgArgs = Array.prototype.slice.call(args, 1);
+      }
+
+      // Build up the record object.
+      var rec = objCopy(log.fields);
+      var level = rec.level = minLevel;
+      var recFields = (fields ? objCopy(fields) : null);
+      if (recFields) {
+        if (log.serializers) {
+          log._applySerializers(recFields);
+        }
+        Object.keys(recFields).forEach(function (k) {
+          rec[k] = recFields[k];
+        });
+      }
+      rec.msg = format.apply(log, msgArgs);
+      if (!rec.time) {
+        rec.time = (new Date());
+      }
+      // Get call source info
+      if (log.src && !rec.src) {
+        rec.src = getCaller3Info()
+      }
+      rec.v = LOG_VERSION;
+
+      return rec;
+    };
+
+    var fields = null;
+    var msgArgs = arguments;
+    var str = null;
+    var rec = null;
     if (arguments.length === 0) {   // `log.<level>()`
       return (this._level <= minLevel);
     } else if (this._level > minLevel) {
-      return;
-    } else if (arguments[0] instanceof Error) {
-      // `log.<level>(err, ...)`
-      fields = {err: errSerializer(arguments[0])};
-      if (arguments.length === 1) {
-        msgArgs = [fields.err.message];
-      } else {
-        msgArgs = Array.prototype.slice.call(arguments, 1);
-      }
-    } else if (typeof (arguments[0]) === 'string') {  // `log.<level>(msg, ...)`
-      fields = null;
-      msgArgs = Array.prototype.slice.call(arguments);
-    } else if (Buffer.isBuffer(arguments[0])) {  // `log.<level>(buf, ...)`
-      // Almost certainly an error, show `inspect(buf)`. See bunyan issue #35.
-      fields = null;
-      msgArgs = Array.prototype.slice.call(arguments);
-      msgArgs[0] = util.inspect(msgArgs[0]);
-    } else {  // `log.<level>(fields, msg, ...)`
-      fields = arguments[0];
-      msgArgs = Array.prototype.slice.call(arguments, 1);
+      /* pass through */
+    } else {
+      rec = mkRecord(msgArgs);
+      str = this._emit(rec);
     }
-    var rec = this._mkRecord(fields, minLevel, msgArgs);
-    this._emit(rec);
+    probes && probes[minLevel].fire(function () {
+        return [ str ||
+          (rec && log._emit(rec, true)) ||
+          log._emit(mkRecord(msgArgs), true) ];
+    });
   }
@@ -742,0 +791,0 @@ }

package.json

 {
   "name": "bunyan",
-  "version": "0.14.6",
+  "version": "0.15.0",
   "description": "a JSON Logger library for node.js services",
@@ -18,2 +18,5 @@ "author": "Trent Mick <[e-mail]> (http://trentm.com)",
 
+  "dependencies": {
+    "trentm-dtrace-provider": "0.2.4"
+  },
   "devDependencies": {
@@ -20,0 +23,0 @@ "tap": "0.2.0",

README.md

@@ -520,2 +520,98 @@ Bunyan is **a simple and fast a JSON logging library** for node.js services and
 
+# DTrace support
+
+On systems that support DTrace (e.g., MacOS, FreeBSD, illumos derivatives
+like SmartOS and OmniOS), Bunyan will create a DTrace provider (`bunyan`)
+that makes available the following probes:
+
+    log-trace
+    log-debug
+    log-info
+    log-warn
+    log-error
+    log-fatal
+
+Each of these probes has a single argument: the string that would be
+written to the log.  Note that when a probe is enabled, it will
+fire whenever the corresponding function is called, even if the level of
+the log message is less than that of any stream.
+
+## DTrace examples
+
+Trace all log messages coming from any Bunyan module on the system.
+(The `-x strsize=4k` is to raise dtrace's default 256 byte buffer size
+because log messages are longer than typical dtrace probes.)
+
+    dtrace -x strsize=4k -qn 'bunyan*:::log-*{printf("%d: %s: %s", pid, probefunc, copyinstr(arg0))}'
+
+Trace all log messages coming from the "wuzzle" component:
+
+    dtrace -x strsize=4k -qn 'bunyan*:::log-*/strstr(this->str = copyinstr(arg0), "\"component\":\"wuzzle\"") != NULL/{printf("%s", this->str)}'
+
+Aggregate debug messages from process 1234, by message:
+
+    dtrace -x strsize=4k -n 'bunyan1234:::log-debug{@[copyinstr(arg0)] = count()}'
+
+On systems that support the
+[`jstack`](http://dtrace.org/blogs/dap/2012/04/25/profiling-node-js/) action
+via a node.js helper, get a stack backtrace for any debug message that
+includes the string "danger!":
+
+    dtrace -x strsize=4k -qn 'log-debug/strstr(copyinstr(arg0), "danger!") != NULL/{printf("\n%s", copyinstr(arg0)); jstack()}'
+
+Output of the above might be:
+
+    {"name":"foo","hostname":"763bf293-d65c-42d5-872b-4abe25d5c4c7.local","pid":12747,"level":20,"msg":"danger!","time":"2012-10-30T18:28:57.115Z","v":0}
+
+              node`0x87e2010
+              DTraceProviderBindings.node`usdt_fire_probe+0x32
+              DTraceProviderBindings.node`_ZN4node11DTraceProbe5_fireEN2v85LocalINS1_5ValueEEE+0x32d
+              DTraceProviderBindings.node`_ZN4node11DTraceProbe4FireERKN2v89ArgumentsE+0x77
+              << internal code >>
+              (anon) as (anon) at /root/node-bunyan/lib/bunyan.js position 40484
+              << adaptor >>
+              (anon) as doit at /root/my-prog.js position 360
+              (anon) as list.ontimeout at timers.js position 4960
+              << adaptor >>
+              << internal >>
+              << entry >>
+              node`_ZN2v88internalL6InvokeEbNS0_6HandleINS0_10JSFunctionEEENS1_INS0_6ObjectEEEiPS5_Pb+0x101
+              node`_ZN2v88internal9Execution4CallENS0_6HandleINS0_6ObjectEEES4_iPS4_Pbb+0xcb
+              node`_ZN2v88Function4CallENS_6HandleINS_6ObjectEEEiPNS1_INS_5ValueEEE+0xf0
+              node`_ZN4node12MakeCallbackEN2v86HandleINS0_6ObjectEEENS1_INS0_8FunctionEEEiPNS1_INS0_5ValueEEE+0x11f
+              node`_ZN4node12MakeCallbackEN2v86HandleINS0_6ObjectEEENS1_INS0_6StringEEEiPNS1_INS0_5ValueEEE+0x66
+              node`_ZN4node9TimerWrap9OnTimeoutEP10uv_timer_si+0x63
+              node`uv__run_timers+0x66
+              node`uv__run+0x1b
+              node`uv_run+0x17
+              node`_ZN4node5StartEiPPc+0x1d0
+              node`main+0x1b
+              node`_start+0x83
+
+              node`0x87e2010
+              DTraceProviderBindings.node`usdt_fire_probe+0x32
+              DTraceProviderBindings.node`_ZN4node11DTraceProbe5_fireEN2v85LocalINS1_5ValueEEE+0x32d
+              DTraceProviderBindings.node`_ZN4node11DTraceProbe4FireERKN2v89ArgumentsE+0x77
+              << internal code >>
+              (anon) as (anon) at /root/node-bunyan/lib/bunyan.js position 40484
+              << adaptor >>
+              (anon) as doit at /root/my-prog.js position 360
+              (anon) as list.ontimeout at timers.js position 4960
+              << adaptor >>
+              << internal >>
+              << entry >>
+              node`_ZN2v88internalL6InvokeEbNS0_6HandleINS0_10JSFunctionEEENS1_INS0_6ObjectEEEiPS5_Pb+0x101
+              node`_ZN2v88internal9Execution4CallENS0_6HandleINS0_6ObjectEEES4_iPS4_Pbb+0xcb
+              node`_ZN2v88Function4CallENS_6HandleINS_6ObjectEEEiPNS1_INS_5ValueEEE+0xf0
+              node`_ZN4node12MakeCallbackEN2v86HandleINS0_6ObjectEEENS1_INS0_8FunctionEEEiPNS1_INS0_5ValueEEE+0x11f
+              node`_ZN4node12MakeCallbackEN2v86HandleINS0_6ObjectEEENS1_INS0_6StringEEEiPNS1_INS0_5ValueEEE+0x66
+              node`_ZN4node9TimerWrap9OnTimeoutEP10uv_timer_si+0x63
+              node`uv__run_timers+0x66
+              node`uv__run+0x1b
+              node`uv_run+0x17
+              node`_ZN4node5StartEiPPc+0x1d0
+              node`main+0x1b
+              node`_start+0x83
+
+
 # Versioning
@@ -531,3 +627,2 @@
 
-
 # License
@@ -534,0 +629,0 @@

New alerts

License Policy Violation

License

This package is not allowed per your license policy. Review the package's license to ensure compliance.

Found 1 instance in 1 package

Environment variable access

Supply chain risk

Package accesses environment variables, which may be a sign of credential stuffing or data theft.

Found 1 instance in 1 package

Mixed license

License

(Experimental) Package contains multiple licenses.

Found 1 instance in 1 package

Fixed alerts

License Policy Violation

License

This package is not allowed per your license policy. Review the package's license to ensure compliance.

Found 1 instance in 1 package

Improved metrics

Total package byte prevSize

265688

increased by13.62%

Number of package files

53

increased by15.22%

Lines of code

2464

increased by4.67%

Number of lines in readme file

635

increased by17.59%

Worsened metrics

Dependency count

1

increased byInfinity%

Number of low license alerts

4

increased by33.33%

Number of low supply chain risk alerts

3

increased by50%

Number of medium supply chain risk alerts

5

increased by25%

Dependency changes

• + Addedtrentm-dtrace-provider@0.2.4

• + Addedtrentm-dtrace-provider@0.2.4(transitive)