Skip to content

Commit

Permalink
issue #56: bunyan -p NAME
Browse files Browse the repository at this point in the history
  • Loading branch information
@trentm
trentm committed Nov 13, 2012
1 parent 9d7bd77 commit f08c2e6
Show file tree
Hide file tree
Showing 7 changed files with 193 additions and 73 deletions.
10 changes: 9 additions & 1 deletion CHANGES.md
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down
9 changes: 9 additions & 0 deletions README.md
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down
2 changes: 1 addition & 1 deletion TODO.md
View file
Original file line number Diff line number Diff line change
@@ -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.
Expand Down Expand Up @@ -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.
Expand Down
201 changes: 143 additions & 58 deletions bin/bunyan
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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);

Expand Down Expand Up @@ -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");
Expand Down Expand Up @@ -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.
Expand Down Expand Up @@ -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":
Expand Down Expand Up @@ -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;
}
if (length > 1) {
handleLogLine(null, leftover + lines[0], opts, stylize);
getPids(function (errCode, pids) {
if (errCode) {
return callback(errCode);
}
leftover = lines.pop();
length -= 1;
for (var i=1; i < length; i++) {
handleLogLine(null, lines[i], 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);
}
});

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.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);
}
dtrace.stderr.pipe(process.stderr);
dtrace.stderr.on('end', countdownToFinish);
dtrace.stderr.on('end', countdownToFinish);
dtrace.on('exit', countdownToFinish);
}
});
}


Expand Down Expand Up @@ -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) {
Expand Down
14 changes: 10 additions & 4 deletions docs/bunyan.1
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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\.
Expand Down Expand Up @@ -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:
Expand Down Expand Up @@ -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"
.
Expand Down
16 changes: 11 additions & 5 deletions docs/bunyan.1.html
View file

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

Loading

0 comments on commit f08c2e6

Please sign in to comment.