diff --git a/CHANGES.md b/CHANGES.md index 7a33fc2..24389eb 100644 --- a/CHANGES.md +++ b/CHANGES.md @@ -2,7 +2,15 @@ ## bunyan 0.16.6 (not yet released) -(nothing yet) +- [issue #56] Support `bunyan -p NAME` to dtrace all PIDs matching 'NAME' in + their command and args (using `ps -A -o pid,command | grep NAME` or, on SunOS + `pgrep -lf NAME`). E.g.: + + bunyan -p myappname + + This is useful for usage of node's [cluster + module](http://nodejs.org/docs/latest/api/all.html#all_cluster) where you'll + have multiple worker processes. ## bunyan 0.16.5 diff --git a/README.md b/README.md index b6115fb..e42c8ba 100644 --- a/README.md +++ b/README.md @@ -551,6 +551,15 @@ Aggregate debug messages from process 1234, by message: dtrace -x strsize=4k -n 'bunyan1234:::log-debug{@[copyinstr(arg0)] = count()}' +Have the bunyan CLI pretty-print the traced logs: + + dtrace -x strsize=4k -qn 'bunyan1234:::log-*{printf("%s", copyinstr(arg0))}' | bunyan + +A convenience handle has been made for this: + + bunyan -p 1234 + + 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 diff --git a/TODO.md b/TODO.md index db1877e..efbf848 100644 --- a/TODO.md +++ b/TODO.md @@ -1,4 +1,3 @@ -- -p PID: proper handling of '-l level' - "all" or "off" levels? log4j? logging.py? logging.py has NOTSET === 0. I think that is only needed/used for multi-level hierarchical effective level. @@ -42,6 +41,7 @@ - Think about a bunyan dashboard that supports organizing and viewing logs from multiple hosts and services. - Syslog support. +- doc the restify RequestCaptureStream usage of RingBuffer. Great example. - A vim plugin (a la http://vim.cybermirror.org/runtime/autoload/zip.vim ?) to allow browsing (read-only) a bunyan log in rendered form. - Some speed comparisons with others to get a feel for Bunyan's speed. diff --git a/bin/bunyan b/bin/bunyan index 3afa088..eb4ecbb 100755 --- a/bin/bunyan +++ b/bin/bunyan @@ -13,7 +13,10 @@ var vm = require('vm'); var http = require('http'); var fs = require('fs'); var warn = console.warn; -var spawn = require('child_process').spawn; +var child_process = require('child_process'), + spawn = child_process.spawn, + exec = child_process.exec, + execFile = child_process.execFile; var nodeSpawnSupportsStdio = (Number(process.version.split('.')[1]) >= 8); @@ -151,7 +154,10 @@ function printHelp() { console.log(""); console.log("Dtrace options (only on dtrace-supporting platforms):"); console.log(" -p PID Process bunyan:log-* probes from the process"); - console.log(" with the given PID."); + console.log(" with the given PID. Can be used multiple times,"); + console.log(" or specify all processes with '*', or a set of"); + console.log(" processes whose command & args match a pattern"); + console.log(" with '-p NAME'."); console.log(""); console.log("Filtering options:"); console.log(" -l, --level LEVEL"); @@ -324,7 +330,8 @@ function parseArgv(argv) { level: null, conditions: null, strict: false, - pid: null + pids: null, + pidsType: null }; // Turn '-iH' into '-i -H', except for argument-accepting options. @@ -400,16 +407,29 @@ function parseArgv(argv) { parsed.outputMode = OM_JSON; break; case "-p": + if (!parsed.pids) { + parsed.pids = []; + } var pidArg = args.shift(); var pid = +(pidArg); - if (isNaN(pid)) { - if (pidArg === '*') { - pid = '*' - } else { - throw new Error(format('invalid pid: "%s"', pidArg)); + if (!isNaN(pid) || pidArg === '*') { + if (parsed.pidsType && parsed.pidsType !== 'num') { + throw new Error(format( + 'cannot mix PID name and number arguments: "%s"', pidArg)); } + parsed.pidsType = 'num'; + if (!parsed.pids) { + parsed.pids = []; + } + parsed.pids.push(isNaN(pid) ? pidArg : pid); + } else { + if (parsed.pidsType && parsed.pidsType !== 'name') { + throw new Error(format( + 'cannot mix PID name and number arguments: "%s"', pidArg)); + } + parsed.pidsType = 'name'; + parsed.pids = pidArg; } - parsed.pid = pid; break; case "-l": case "--level": @@ -913,62 +933,127 @@ function processStdin(opts, stylize, callback) { * @param stylize {Function} Output stylize function to use. * @param callback {Function} `function (code)` */ -function processPid(opts, stylize, callback) { +function processPids(opts, stylize, callback) { var leftover = ""; // Left-over partial line from last chunk. - var argv = ['dtrace', '-Z', '-x', 'strsize=4k', '-qn', - format('bunyan%s:::log-*{printf("%s", copyinstr(arg0))}', opts.pid)]; - var dtrace = spawn(argv[0], argv.slice(1), - // Share the stderr handle to have error output come - // straight through. Only supported in v0.8+. - {stdio: ['pipe', 'pipe', process.stderr]}); - child = dtrace; // intentionally global - function finish(code) { - if (leftover) { - handleLogLine(null, leftover, opts, stylize); - leftover = ''; + /** + * Get the PIDs to dtrace. + * + * @param cb {Function} `function (errCode, pids)` + */ + function getPids(cb) { + if (opts.pidsType === 'num') { + return cb(null, opts.pids); + } + if (process.platform === 'sunos') { + execFile('/bin/pgrep', ['-lf', opts.pids], + function (pidsErr, stdout, stderr) { + if (pidsErr) { + warn('bunyan: error getting PIDs for "%s": %s\n%s\n%s', + opts.pids, pidsErr.message, stdout, stderr); + return cb(1); + } + var pids = stdout.trim().split('\n') + .map(function (line) { return line.trim().split(/\s+/)[0] }) + .filter(function (pid) { return Number(pid) !== process.pid }); + if (pids.length === 0) { + warn('bunyan: error: no matching PIDs found for "%s"', opts.pids); + return cb(2); + } + cb(null, pids); + } + ); + } else { + var regex = opts.pids; + if (regex && /[a-zA-Z0-9_]/.test(regex[0])) { + // 'foo' -> '[f]oo' trick to exclude the 'grep' PID from its own + // search. + regex = '[' + regex[0] + ']' + regex.slice(1); + } + exec(format('ps -A -o pid,command | grep \'%s\'', regex), + function (pidsErr, stdout, stderr) { + if (pidsErr) { + warn('bunyan: error getting PIDs for "%s": %s\n%s\n%s', + opts.pids, pidsErr.message, stdout, stderr); + return cb(1); + } + var pids = stdout.trim().split('\n') + .map(function (line) { return line.trim().split(/\s+/)[0] }) + .filter(function (pid) { return Number(pid) !== process.pid }); + if (pids.length === 0) { + warn('bunyan: error: no matching PIDs found for "%s"', opts.pids); + return cb(2); + } + cb(null, pids); + } + ); } - callback(returnCode); } - dtrace.stdout.setEncoding('utf8'); - dtrace.stdout.on('data', function (chunk) { - var lines = chunk.split(/\r\n|\n/); - var length = lines.length; - if (length === 1) { - leftover += lines[0]; - return; + getPids(function (errCode, pids) { + if (errCode) { + return callback(errCode); } - if (length > 1) { - handleLogLine(null, leftover + lines[0], opts, stylize); + + var probes = pids.map(function (pid) { + return format('bunyan%s:::log-*', pid); + }).join(','); + var argv = ['dtrace', '-Z', '-x', 'strsize=4k', '-qn', + format('%s{printf("%s", copyinstr(arg0))}', probes)]; + //console.log('dtrace argv: %s', argv); + var dtrace = spawn(argv[0], argv.slice(1), + // Share the stderr handle to have error output come + // straight through. Only supported in v0.8+. + {stdio: ['pipe', 'pipe', process.stderr]}); + child = dtrace; // intentionally global + + function finish(code) { + if (leftover) { + handleLogLine(null, leftover, opts, stylize); + leftover = ''; + } + callback(returnCode); } - leftover = lines.pop(); - length -= 1; - for (var i=1; i < length; i++) { - handleLogLine(null, lines[i], opts, stylize); + + dtrace.stdout.setEncoding('utf8'); + dtrace.stdout.on('data', function (chunk) { + var lines = chunk.split(/\r\n|\n/); + var length = lines.length; + if (length === 1) { + leftover += lines[0]; + return; + } + if (length > 1) { + handleLogLine(null, leftover + lines[0], opts, stylize); + } + leftover = lines.pop(); + length -= 1; + for (var i=1; i < length; i++) { + handleLogLine(null, lines[i], opts, stylize); + } + }); + + if (nodeSpawnSupportsStdio) { + dtrace.on('exit', finish); + } else { + // Fallback (for < v0.8) to pipe the dtrace process' stderr to this stderr. + // Wait for all of (1) process 'exit', (2) stderr 'end', and (2) stdout + // 'end' before returning to ensure all stderr is flushed (issue #54). + var returnCode = null; + var eventsRemaining = 3; + function countdownToFinish(code) { + returnCode = code; + eventsRemaining--; + if (eventsRemaining == 0) { + finish(returnCode); + } + } + dtrace.stderr.pipe(process.stderr); + dtrace.stderr.on('end', countdownToFinish); + dtrace.stderr.on('end', countdownToFinish); + dtrace.on('exit', countdownToFinish); } }); - - if (nodeSpawnSupportsStdio) { - dtrace.on('exit', finish); - } else { - // Fallback (for < v0.8) to pipe the dtrace process' stderr to this stderr. - // Wait for all of (1) process 'exit', (2) stderr 'end', and (2) stdout - // 'end' before returning to ensure all stderr is flushed (issue #54). - var returnCode = null; - var eventsRemaining = 3; - function countdownToFinish(code) { - returnCode = code; - eventsRemaining--; - if (eventsRemaining == 0) { - finish(returnCode); - } - } - dtrace.stderr.pipe(process.stderr); - dtrace.stderr.on('end', countdownToFinish); - dtrace.stderr.on('end', countdownToFinish); - dtrace.on('exit', countdownToFinish); - } } @@ -1133,8 +1218,8 @@ function main(argv) { var stylize = (opts.color ? stylizeWithColor : stylizeWithoutColor); var retval = 0; - if (opts.pid) { - processPid(opts, stylize, function (code) { + if (opts.pids) { + processPids(opts, stylize, function (code) { process.exit(code); }); } else if (opts.args.length > 0) { diff --git a/docs/bunyan.1 b/docs/bunyan.1 index a826c98..d10debe 100644 --- a/docs/bunyan.1 +++ b/docs/bunyan.1 @@ -7,7 +7,13 @@ \fBbunyan\fR \- filter and pretty\-print Bunyan log file content . .SH "SYNOPSIS" -\fBbunyan\fR [OPTIONS] [LOOKUPS\.\.\.] \.\.\. | \fBbunyan\fR [OPTIONS] \fBbunyan\fR [OPTIONS] \-p PID +\fBbunyan\fR [OPTIONS] +. +.P +\&\.\.\. | \fBbunyan\fR [OPTIONS] +. +.P +\fBbunyan\fR [OPTIONS] \-p PID . .SH "DESCRIPTION" "Bunyan" is \fBa simple and fast a JSON logging library\fR for node\.js services, a one\-JSON\-object\-per\-line log format, and \fBa \fBbunyan\fR CLI tool\fR for nicely viewing those logs\. This man page describes the latter\. @@ -99,8 +105,8 @@ Don\'t warn if input isn\'t valid JSON\. Dtrace options (only on dtrace\-supporting platforms): . .TP -\fB\-p PID\fR -Process bunyan:log\-* probes from the process with the given PID\. +\fB\-p PID\fR, \fB\-p NAME\fR +Process bunyan:log\-* probes from the process with the given PID\. Can be used multiple times, or specify all processes with \'*\', or a set of processes whose command & args match a pattern with \'\-p NAME\'\. . .P Filtering options: @@ -195,7 +201,7 @@ 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\. . .P -See \fIhttps://github\.com/trentm/node\-bunyan#dtrace\-support\fR for more details\. +See \fIhttps://github\.com/trentm/node\-bunyan#dtrace\-support\fR for more details and the \'\-p PID\' option above for convenience usage\. . .SH "ENVIRONMENT" . diff --git a/docs/bunyan.1.html b/docs/bunyan.1.html index 70577fb..bc2c525 100644 --- a/docs/bunyan.1.html +++ b/docs/bunyan.1.html @@ -85,9 +85,11 @@
bunyan
[OPTIONS] [LOOKUPS...]
-... | bunyan
[OPTIONS]
-bunyan
[OPTIONS] -p PID
bunyan
[OPTIONS]
... | bunyan
[OPTIONS]
bunyan
[OPTIONS] -p PID
this
refers to the record object:Dtrace options (only on dtrace-supporting platforms):
-p PID
-p PID
, -p NAME
See https://github.com/trentm/node-bunyan#dtrace-support for more details.
+See https://github.com/trentm/node-bunyan#dtrace-support for more details +and the '-p PID' option above for convenience usage.