node-bunyan-lite/bin/bunyan

#!/usr/bin/env node
//
// bunyan -- filter and pretty-print JSON logs, like Bunyan logs.
//
// See <https://github.com/trentm/node-bunyan>.
//

var VERSION = "0.18.0";

var util = require('util');
var pathlib = require('path');
var vm = require('vm');
var http = require('http');
var fs = require('fs');
var warn = console.warn;
var child_process = require('child_process'),
  spawn = child_process.spawn,
  exec = child_process.exec,
  execFile = child_process.execFile;
var assert = require('assert');

var nodeSpawnSupportsStdio = (
  Number(process.version.split('.')[0]) >= 0
  || Number(process.version.split('.')[1]) >= 8);



//---- globals and constants

// Internal debug logging via `console.warn`.
var _DEBUG = false;

// Output modes.
var OM_PAUL = 1;
var OM_JSON = 2;
var OM_INSPECT = 3;
var OM_SIMPLE = 4;
var OM_SHORT = 5;
var OM_FROM_NAME = {
  "paul": OM_PAUL,
  "json": OM_JSON,
  "inspect": OM_INSPECT,
  "simple": OM_SIMPLE,
  "short": OM_SHORT
};


// Levels
var TRACE = 10;
var DEBUG = 20;
var INFO = 30;
var WARN = 40;
var ERROR = 50;
var FATAL = 60;

var levelFromName = {
  'trace': TRACE,
  'debug': DEBUG,
  'info': INFO,
  'warn': WARN,
  'error': ERROR,
  'fatal': FATAL
};
var nameFromLevel = {};
var upperNameFromLevel = {};
var upperPaddedNameFromLevel = {};
Object.keys(levelFromName).forEach(function (name) {
  var lvl = levelFromName[name];
  nameFromLevel[lvl] = name;
  upperNameFromLevel[lvl] = name.toUpperCase();
  upperPaddedNameFromLevel[lvl] = (
    name.length === 4 ? ' ' : '') + name.toUpperCase();
});


// The current raw input line being processed. Used for `uncaughtException`.
var currLine = null;

// Child dtrace process, if any. Used for signal-handling.
var child = null;

// Whether ANSI codes are being used. Used for signal-handling.
var usingAnsiCodes = false;

// Global ref to options used only by 'uncaughtException' handler.
var gOptsForUncaughtException;

// Pager child process, and output stream to which to write.
var pager = null;
var stdout = process.stdout;



//---- support functions

function getVersion() {
  return VERSION;
}


var format = util.format;
if (!format) {
  // If not node 0.6, then use its `util.format`:
  // <https://github.com/joyent/node/blob/master/lib/util.js#L22>:
  var inspect = util.inspect;
  var formatRegExp = /%[sdj%]/g;
  format = function format(f) {
    if (typeof f !== 'string') {
      var objects = [];
      for (var i = 0; i < arguments.length; i++) {
        objects.push(inspect(arguments[i]));
      }
      return objects.join(' ');
    }

    var i = 1;
    var args = arguments;
    var len = args.length;
    var str = String(f).replace(formatRegExp, function(x) {
      if (i >= len) return x;
      switch (x) {
        case '%s': return String(args[i++]);
        case '%d': return Number(args[i++]);
        case '%j': return JSON.stringify(args[i++]);
        case '%%': return '%';
        default:
          return x;
      }
    });
    for (var x = args[i]; i < len; x = args[++i]) {
      if (x === null || typeof x !== 'object') {
        str += ' ' + x;
      } else {
        str += ' ' + inspect(x);
      }
    }
    return str;
  };
}

function indent(s) {
  return '    ' + s.split(/\r?\n/).join('\n    ');
}

function objCopy(obj) {
  if (obj === null) {
    return null;
  } else if (Array.isArray(obj)) {
    return obj.slice();
  } else {
    var copy = {};
    Object.keys(obj).forEach(function (k) {
      copy[k] = obj[k];
    });
    return copy;
  }
}

function printHelp() {
  console.log("Usage:");
  console.log("  bunyan [OPTIONS] [FILE ...]");
  console.log("  ... | bunyan [OPTIONS]");
  console.log("  bunyan [OPTIONS] -p PID");
  console.log("");
  console.log("Filter and pretty-print Bunyan log file content.");
  console.log("");
  console.log("General options:");
  console.log("  -h, --help    print this help info and exit");
  console.log("  --version     print version of this command and exit");
  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. 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");
  console.log("                Only show messages at or above the specified level.");
  console.log("                You can specify level *names* or numeric values.");
  console.log("                (See 'Log Levels' below.)");
  console.log("  -c, --condition CONDITION");
  console.log("                Run each log message through the condition and");
  console.log("                only show those that return truish. E.g.:");
  console.log("                    -c 'this.pid == 123'");
  console.log("                    -c 'this.level == DEBUG'");
  console.log("                    -c 'this.msg.indexOf(\"boom\") != -1'");
  console.log("                'CONDITION' must be legal JS code. `this` holds");
  console.log("                the log record. The TRACE, DEBUG, ... FATAL values");
  console.log("                are defined to help with comparing `this.level`.");
  console.log("  --strict      Suppress all but legal Bunyan JSON log lines. By default");
  console.log("                non-JSON, and non-Bunyan lines are passed through.");
  console.log("");
  console.log("Output options:");
  console.log("  --pager       Pipe output into `less` (or $PAGER if set), if");
  console.log("                stdout is a terminal. This overrides $BUNYAN_NO_PAGER.");
  console.log("                Note: Paging is only supported on node >=0.8.");
  console.log("  --no-pager    Do not pipe output into a pager.");
  console.log("  --color       Colorize output. Defaults to try if output");
  console.log("                stream is a TTY.");
  console.log("  --no-color    Force no coloring (e.g. terminal doesn't support it)");
  console.log("  -o, --output MODE");
  console.log("                Specify an output mode/format. One of");
  console.log("                  paul: (the default) pretty");
  console.log("                  json: JSON output, 2-space indent");
  console.log("                  json-N: JSON output, N-space indent, e.g. 'json-4'");
  console.log("                  inspect: node.js `util.inspect` output");
  console.log("                  short: like paul, but more concise");
  console.log("  -j            shortcut for `-o json`");
  console.log("");
  console.log("Log Levels:");
  console.log("  Either numeric values or their associated strings are valid for the");
  console.log("  -l|--level argument.  However, -c|--condition scripts will see a numeric");
  console.log("  'level' value, not a string.");
  console.log("");
  Object.keys(levelFromName).forEach(function(name) {
    var n = name;
    while (n.length < 6)
      n += " ";
    console.log("    %s %d", n, levelFromName[name]);
  });
  console.log("");
  console.log("Environment Variables:");
  console.log("  BUNYAN_NO_COLOR    Set to a non-empty value to force no output ");
  console.log("                     coloring. See '--no-color'.");
  console.log("  BUNYAN_NO_PAGER    Disable piping output to a pager. ");
  console.log("                     See '--no-pager'.");
  console.log("");
  console.log("See <https://github.com/trentm/node-bunyan> for more complete docs.");
  console.log("Please report bugs to <https://github.com/trentm/node-bunyan/issues>.");
}

/*
 * If the user specifies multiple input sources, we want to print out records
 * from all sources in a single, chronologically ordered stream.  To do this
 * efficiently, we first assume that all records within each source are ordered
 * already, so we need only keep track of the next record in each source and
 * the time of the last record emitted.  To avoid excess memory usage, we
 * pause() streams that are ahead of others.
 *
 * "streams" is an object indexed by source name (file name) which specifies:
 *
 *    stream        Actual stream object, so that we can pause and resume it.
 *
 *    records       Array of log records we've read, but not yet emitted.  Each
 *                  record includes "line" (the raw line), "rec" (the JSON
 *                  record), and "time" (the parsed time value).
 *
 *    done          Whether the stream has any more records to emit.
 */
var streams = {};

function gotRecord(file, line, rec, opts, stylize)
{
  var time = new Date(rec.time);

  streams[file]['records'].push({ line: line, rec: rec, time: time });
  emitNextRecord(opts, stylize);
}

function filterRecord(rec, opts)
{
  if (opts.level && rec.level < opts.level) {
    return false;
  }

  if (opts.conditions) {
    for (var i = 0; i < opts.conditions.length; i++) {
      var pass = opts.conditions[i].runInNewContext(rec);
      if (!pass)
        return false;
    }
  }

  return true;
}

function emitNextRecord(opts, stylize)
{
  var ofile, ready, minfile, rec;

  for (;;) {
    /*
     * Take a first pass through the input streams to see if we have a record
     * from all of them.  If not, we'll pause any streams for which we do
     * already have a record (to avoid consuming excess memory) and then wait
     * until we have records from the others before emitting the next record.
     *
     * As part of the same pass, we look for the earliest record we have not yet
     * emitted.
     */
    minfile = undefined;
    ready = true;
    for (ofile in streams) {

      if (streams[ofile].stream === null ||
        (!streams[ofile].done && streams[ofile].records.length === 0)) {
        ready = false;
        break;
      }

      if (streams[ofile].records.length > 0 && (minfile === undefined ||
          streams[minfile].records[0].time > streams[ofile].records[0].time)) {
        minfile = ofile;
      }
    }

    if (!ready || minfile === undefined) {
      for (ofile in streams) {
        if (!streams[ofile].stream || streams[ofile].done)
          continue;

        if (streams[ofile].records.length > 0) {
          if (!streams[ofile].paused) {
            streams[ofile].paused = true;
            streams[ofile].stream.pause();
          }
        } else if (streams[ofile].paused) {
          streams[ofile].paused = false;
          streams[ofile].stream.resume();
        }
      }

      return;
    }

    /*
     * Emit the next record for "minfile", and invoke ourselves again to make
     * sure we emit as many records as we can right now.
     */
    rec = streams[minfile].records.shift();
    emitRecord(rec.rec, rec.line, opts, stylize);
  }
}

/**
 * Parse the command-line options and arguments into an object.
 *
 *    {
 *      'args': [...]       // arguments
 *      'help': true,       // true if '-h' option given
 *       // etc.
 *    }
 *
 * @return {Object} The parsed options. `.args` is the argument list.
 * @throws {Error} If there is an error parsing argv.
 */
function parseArgv(argv) {
  var parsed = {
    args: [],
    help: false,
    color: null,
    paginate: null,
    outputMode: OM_PAUL,
    jsonIndent: 2,
    level: null,
    conditions: null,
    strict: false,
    pids: null,
    pidsType: null
  };

  // Turn '-iH' into '-i -H', except for argument-accepting options.
  var args = argv.slice(2);  // drop ['node', 'scriptname']
  var newArgs = [];
  var optTakesArg = {'d': true, 'o': true, 'c': true, 'l': true, 'p': true};
  for (var i = 0; i < args.length; i++) {
    if (args[i].charAt(0) === "-" && args[i].charAt(1) !== '-' && args[i].length > 2) {
      var splitOpts = args[i].slice(1).split("");
      for (var j = 0; j < splitOpts.length; j++) {
        newArgs.push('-' + splitOpts[j]);
        if (optTakesArg[splitOpts[j]]) {
          var optArg = splitOpts.slice(j+1).join("");
          if (optArg.length) {
            newArgs.push(optArg);
          }
          break;
        }
      }
    } else {
      newArgs.push(args[i]);
    }
  }
  args = newArgs;

  var condDefines = [];
  Object.keys(upperNameFromLevel).forEach(function (lvl) {
    condDefines.push(
      format("Object.prototype.%s = %s;", upperNameFromLevel[lvl], lvl));
  });
  condDefines = condDefines.join('\n') + '\n';

  var endOfOptions = false;
  while (args.length > 0) {
    var arg = args.shift();
    switch(arg) {
      case "--":
        endOfOptions = true;
        break;
      case "-h": // display help and exit
      case "--help":
        parsed.help = true;
        break;
      case "--version":
        parsed.version = true;
        break;
      case "--strict":
        parsed.strict = true;
        break;
      case "--color":
        parsed.color = true;
        break;
      case "--no-color":
        parsed.color = false;
        break;
      case "--pager":
        parsed.paginate = true;
        break;
      case "--no-pager":
        parsed.paginate = false;
        break;
      case "-o":
      case "--output":
        var name = args.shift();
        var idx = name.lastIndexOf('-');
        if (idx !== -1) {
          var indentation = Number(name.slice(idx+1));
          if (! isNaN(indentation)) {
            parsed.jsonIndent = indentation;
            name = name.slice(0, idx);
          }
        }
        parsed.outputMode = OM_FROM_NAME[name];
        if (parsed.outputMode === undefined) {
          throw new Error("unknown output mode: '"+name+"'");
        }
        break;
      case "-j": // output with JSON.stringify
        parsed.outputMode = OM_JSON;
        break;
      case "-p":
        if (!parsed.pids) {
          parsed.pids = [];
        }
        var pidArg = args.shift();
        var pid = +(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;
        }
        break;
      case "-l":
      case "--level":
        var levelArg = args.shift();
        var level = +(levelArg);
        if (isNaN(level)) {
          level = +levelFromName[levelArg.toLowerCase()];
        }
        if (isNaN(level)) {
          throw new Error("unknown level value: '"+levelArg+"'");
        }
        parsed.level = level;
        break;
      case "-c":
      case "--condition":
        var condition = args.shift();
        parsed.conditions = parsed.conditions || [];
        var scriptName = 'bunyan-condition-'+parsed.conditions.length;
        var code = condDefines + condition;
        try {
          var script = vm.createScript(code, scriptName);
        } catch (compileErr) {
          throw new Error(format('illegal CONDITION code: %s\n'
            + '  CONDITION script:\n'
            + '%s\n'
            + '  Error:\n'
            + '%s',
            compileErr, indent(code), indent(compileErr.stack)));
        }

        // Ensure this is a reasonably safe CONDITION.
        try {
          script.runInNewContext(minValidRecord);
        } catch (condErr) {
          throw new Error(format(
            'CONDITION code cannot safely filter a minimal Bunyan log record\n'
            + '  CONDITION script:\n'
            + '%s\n'
            + '  Minimal Bunyan log record:\n'
            + '%s\n'
            + '  Filter error:\n'
            + '%s',
            indent(code),
            indent(JSON.stringify(minValidRecord, null, 2)),
            indent(condErr.stack)
            ));
        }

        parsed.conditions.push(script);
        break;
      default: // arguments
        if (!endOfOptions && arg.length > 0 && arg[0] === '-') {
          throw new Error("unknown option '"+arg+"'");
        }
        parsed.args.push(arg);
        break;
    }
  }
  //TODO: '--' handling and error on a first arg that looks like an option.

  return parsed;
}


function isInteger(s) {
  return (s.search(/^-?[0-9]+$/) == 0);
}


// http://en.wikipedia.org/wiki/ANSI_escape_code#graphics
// Suggested colors (some are unreadable in common cases):
// - Good: cyan, yellow (limited use), grey, bold, green, magenta, red
// - Bad: blue (not visible on cmd.exe)
var colors = {
  'bold' : [1, 22],
  'italic' : [3, 23],
  'underline' : [4, 24],
  'inverse' : [7, 27],
  'white' : [37, 39],
  'grey' : [90, 39],
  'black' : [30, 39],
  'blue' : [34, 39],
  'cyan' : [36, 39],
  'green' : [32, 39],
  'magenta' : [35, 39],
  'red' : [31, 39],
  'yellow' : [33, 39]
};

function stylizeWithColor(str, color) {
  if (!str)
    return '';
  var codes = colors[color];
  if (codes) {
    return '\033[' + codes[0] + 'm' + str +
           '\033[' + codes[1] + 'm';
  } else {
    return str;
  }
}

function stylizeWithoutColor(str, color) {
  return str;
}


/**
 * Is this a valid Bunyan log record.
 */
function isValidRecord(rec) {
  if (rec.v == null ||
      rec.level == null ||
      rec.name == null ||
      rec.hostname == null ||
      rec.pid == null ||
      rec.time == null ||
      rec.msg == null) {
    // Not valid Bunyan log.
    return false;
  } else {
    return true;
  }
}
var minValidRecord = {
  v: 0,   //TODO: get this from bunyan.LOG_VERSION
  level: INFO,
  name: 'name',
  hostname: 'hostname',
  pid: 123,
  time: Date.now(),
  msg: 'msg'
};


/**
 * Parses the given log line and either emits it right away (for invalid
 * records) or enqueues it for emitting later when it's the next line to show.
 */
function handleLogLine(file, line, opts, stylize) {
  currLine = line; // intentionally global

  // Emit non-JSON lines immediately.
  var rec;
  if (!line) {
    if (!opts.strict) emit(line + '\n');
    return;
  } else if (line[0] !== '{') {
    if (!opts.strict) emit(line + '\n');  // not JSON
    return;
  } else {
    try {
      rec = JSON.parse(line);
    } catch(e) {
      if (!opts.strict) emit(line + '\n');
      return;
    }
  }

  if (!isValidRecord(rec)) {
    if (!opts.strict) emit(line + '\n');
    return;
  }

  if (!filterRecord(rec, opts))
    return;

  if (file === null)
    return emitRecord(rec, line, opts, stylize);

  return gotRecord(file, line, rec, opts, stylize);
}

/**
 * Print out a single result, considering input options.
 */
function emitRecord(rec, line, opts, stylize) {
  var short = false;

  switch (opts.outputMode) {
  case OM_SHORT:
    short = true;
    /* jsl:fall-thru */

  case OM_PAUL:
    //    [time] LEVEL: name[/component]/pid on hostname (src): msg* (extras...)
    //        msg*
    //        --
    //        long and multi-line extras
    //        ...
    // If 'msg' is single-line, then it goes in the top line.
    // If 'req', show the request.
    // If 'res', show the response.
    // If 'err' and 'err.stack' then show that.
    if (!isValidRecord(rec)) {
      return emit(line + '\n');
    }

    delete rec.v;

    /*
     * We assume the Date is formatted according to ISO8601, in which case we
     * can safely chop off the date information.
     */
    if (short && rec.time[10] == 'T') {
      var time = rec.time.substr(11);
      time = stylize(time, 'XXX');
    } else {
      var time = stylize('[' + rec.time + ']', 'XXX');
    }

    delete rec.time;

    var nameStr = rec.name;
    delete rec.name;

    if (rec.component) {
      nameStr += '/' + rec.component;
    }
    delete rec.component;

    if (!short)
      nameStr += '/' + rec.pid;
    delete rec.pid;

    var level = (upperPaddedNameFromLevel[rec.level] || "LVL" + rec.level);
    if (opts.color) {
      var colorFromLevel = {
        10: 'grey',     // TRACE
        20: 'grey',     // DEBUG
        30: 'cyan',     // INFO
        40: 'magenta',  // WARN
        50: 'red',      // ERROR
        60: 'inverse',  // FATAL
      };
      level = stylize(level, colorFromLevel[rec.level]);
    }
    delete rec.level;

    var src = "";
    if (rec.src && rec.src.file) {
      var s = rec.src;
      if (s.func) {
        src = format(" (%s:%d in %s)", s.file, s.line, s.func);
      } else {
        src = format(" (%s:%d)", s.file, s.line);
      }
      src = stylize(src, 'green');
    }
    delete rec.src;

    var hostname = rec.hostname;
    delete rec.hostname;

    var extras = [];
    var details = [];

    if (rec.req_id) {
      extras.push("req_id=" + rec.req_id);
    }
    delete rec.req_id;

    var onelineMsg;
    if (rec.msg.indexOf('\n') !== -1) {
      onelineMsg = '';
      details.push(indent(stylize(rec.msg, 'cyan')));
    } else {
      onelineMsg = ' ' + stylize(rec.msg, 'cyan');
    }
    delete rec.msg;

    if (rec.req && typeof(rec.req) === 'object') {
      var req = rec.req;
      delete rec.req;
      var headers = req.headers;
      var s = format("%s %s HTTP/%s%s", req.method,
        req.url,
        req.httpVersion || "1.1",
        (headers
          ? '\n' + Object.keys(headers).map(
              function (h) { return h + ': ' + headers[h]; }).join('\n')
          : '')
      );
      delete req.url;
      delete req.method;
      delete req.httpVersion;
      delete req.headers;
      if (req.body) {
        s += '\n\n' + (typeof(req.body) === 'object'
          ? JSON.stringify(req.body, null, 2) : req.body);
        delete req.body;
      }
      if (req.trailers && Object.keys(req.trailers) > 0) {
        s += '\n' + Object.keys(req.trailers).map(
            function (t) { return t + ': ' + req.trailers[t]; }).join('\n');
      }
      delete req.trailers;
      details.push(indent(s));
      // E.g. for extra 'foo' field on 'req', add 'req.foo' at top-level.
      // This *does* have the potential to stomp on a literal 'req.foo' key.
      Object.keys(req).forEach(function (k) {
        rec["req." + k] = req[k];
      })
    }

    if (rec.client_req && typeof(rec.client_req) === 'object') {
      var client_req = rec.client_req;
      delete rec.client_req;
      var headers = client_req.headers;
      var hostHeaderLine = '';
      var s = '';
      if (client_req.address) {
        hostHeaderLine = 'Host: ' + client_req.address;
        if (client_req.port)
          hostHeaderLine += ':' + client_req.port;
        hostHeaderLine += '\n';
      }
      delete client_req.headers;
      delete client_req.address;
      delete client_req.port;
      s += format("%s %s HTTP/%s\n%s%s", client_req.method,
        client_req.url,
        client_req.httpVersion || "1.1",
        hostHeaderLine,
        Object.keys(headers).map(
          function (h) { return h + ': ' + headers[h]; }).join('\n'));
      delete client_req.method;
      delete client_req.url;
      delete client_req.httpVersion;
      if (client_req.body) {
        s += '\n\n' + (typeof(client_req.body) === 'object'
          ? JSON.stringify(client_req.body, null, 2) : client_req.body);
        delete client_req.body;
      }
      // E.g. for extra 'foo' field on 'client_req', add 'client_req.foo' at
      // top-level. This *does* have the potential to stomp on a literal
      // 'client_req.foo' key.
      Object.keys(client_req).forEach(function (k) {
        rec["client_req." + k] = client_req[k];
      })
      details.push(indent(s));
    }

    if (rec.res && typeof(rec.res) === 'object') {
      var res = rec.res;
      delete rec.res;
      var s = '';
      if (res.header) {
        s += res.header.trimRight();
      } else if (res.headers) {
        if (res.statusCode) {
          s += format("HTTP/1.1 %s %s\n", res.statusCode,
            http.STATUS_CODES[res.statusCode]);
        }
        var headers = res.headers;
        s += Object.keys(headers).map(
          function (h) { return h + ': ' + headers[h]; }).join('\n');
      }
      delete res.header;
      delete res.headers;
      delete res.statusCode;
      if (res.body) {
        s += '\n\n' + (typeof(res.body) === 'object'
          ? JSON.stringify(res.body, null, 2) : res.body);
        delete res.body;
      }
      if (res.trailer) {
        s += '\n' + res.trailer;
      }
      delete res.trailer;
      if (s) {
        details.push(indent(s));
      }
      // E.g. for extra 'foo' field on 'res', add 'res.foo' at top-level.
      // This *does* have the potential to stomp on a literal 'res.foo' key.
      Object.keys(res).forEach(function (k) {
        rec["res." + k] = res[k];
      });
    }

    if (rec.err && rec.err.stack) {
      details.push(indent(rec.err.stack));
      delete rec.err;
    }

    var leftover = Object.keys(rec);
    for (var i = 0; i < leftover.length; i++) {
      var key = leftover[i];
      var value = rec[key];
      var stringified = false;
      if (typeof(value) !== 'string') {
        value = JSON.stringify(value, null, 2);
        stringified = true;
      }
      if (value.indexOf('\n') !== -1 || value.length > 50) {
        details.push(indent(key + ': ' + value));
      } else if (!stringified && (value.indexOf(' ') != -1 ||
                                  value.length === 0)) {
        extras.push(key + '=' + JSON.stringify(value));
      } else {
        extras.push(key + '=' + value);
      }
    }

    extras = stylize(
      (extras.length ? ' (' + extras.join(', ') + ')' : ''), 'grey');
    details = stylize(
      (details.length ? details.join('\n    --\n') + '\n' : ''), 'grey');
    if (!short)
      emit(format("%s %s: %s on %s%s:%s%s\n%s",
        time,
        level,
        nameStr,
        hostname || "<no-hostname>",
        src,
        onelineMsg,
        extras,
        details));
    else
      emit(format("%s %s %s:%s%s\n%s",
        time,
        level,
        nameStr,
        onelineMsg,
        extras,
        details));
    break;

  case OM_INSPECT:
    emit(util.inspect(rec, false, Infinity, true) + '\n');
    break;

  case OM_JSON:
    emit(JSON.stringify(rec, null, opts.jsonIndent) + '\n');
    break;

  case OM_SIMPLE:
    // <http://logging.apache.org/log4j/1.2/apidocs/org/apache/log4j/SimpleLayout.html>
    if (!isValidRecord(rec)) {
      return emit(line + '\n');
    }
    emit(format("%s - %s\n", upperNameFromLevel[rec.level] || "LVL" + rec.level,
      rec.msg));
    break;
  default:
    throw new Error("unknown output mode: "+opts.outputMode);
  }
}


var stdoutFlushed = true;
function emit(s) {
  try {
    stdoutFlushed = stdout.write(s);
  } catch (e) {
    // Handle any exceptions in stdout writing in `stdout.on("error", ...)`.
  }
}


/**
 * A hacked up version of "process.exit" that will first drain stdout
 * before exiting. *WARNING: This doesn't stop event processing.* IOW,
 * callers have to be careful that code following this call isn't
 * accidentally executed.
 *
 * In node v0.6 "process.stdout and process.stderr are blocking when they
 * refer to regular files or TTY file descriptors." However, this hack might
 * still be necessary in a shell pipeline.
 */
function drainStdoutAndExit(code) {
  if (_DEBUG) warn('(drainStdoutAndExit(%d))', code);
  stdout.on('drain', function () {
    cleanupAndExit(code);
  });
  if (stdoutFlushed) {
    cleanupAndExit(code);
  }
}


/**
 * Process all input from stdin.
 *
 * @params opts {Object} Bunyan options object.
 * @param stylize {Function} Output stylize function to use.
 * @param callback {Function} `function ()`
 */
function processStdin(opts, stylize, callback) {
  var leftover = "";  // Left-over partial line from last chunk.
  var stdin = process.stdin;
  stdin.resume();
  stdin.setEncoding('utf8');
  stdin.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);
    }
  });
  stdin.on('end', function () {
    if (leftover) {
      handleLogLine(null, leftover, opts, stylize);
      leftover = '';
    }
    callback();
  });
}


/**
 * Process bunyan:log-* probes from the given pid.
 *
 * @params opts {Object} Bunyan options object.
 * @param stylize {Function} Output stylize function to use.
 * @param callback {Function} `function (code)`
 */
function processPids(opts, stylize, callback) {
  var leftover = "";  // Left-over partial line from last chunk.

  /**
   * 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);
        }
      );
    }
  }

  getPids(function (errCode, pids) {
    if (errCode) {
      return callback(errCode);
    }

    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);
    }

    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);
    }
  });
}


/**
 * Process all input from the given log file.
 *
 * @param file {String} Log file path to process.
 * @params opts {Object} Bunyan options object.
 * @param stylize {Function} Output stylize function to use.
 * @param callback {Function} `function ()`
 */
function processFile(file, opts, stylize, callback) {
  var stream = fs.createReadStream(file);
  if (/\.gz$/.test(file)) {
    stream = stream.pipe(require('zlib').createGunzip());
  }
  // Manually decode streams - lazy load here as per node/lib/fs.js
  var decoder = new (require('string_decoder').StringDecoder)('utf8');

  streams[file].stream = stream;

  stream.on('error', function (err) {
    streams[file].done = true;
    callback(err);
  });

  var leftover = '';  // Left-over partial line from last chunk.
  stream.on('data', function (data) {
    var chunk = decoder.write(data);
    if (!chunk.length) {
      return;
    }
    var lines = chunk.split(/\r\n|\n/);
    var length = lines.length;
    if (length === 1) {
      leftover += lines[0];
      return;
    }

    if (length > 1) {
      handleLogLine(file, leftover + lines[0], opts, stylize);
    }
    leftover = lines.pop();
    length -= 1;
    for (var i=1; i < length; i++) {
      handleLogLine(file, lines[i], opts, stylize);
    }
  });

  stream.on('end', function () {
    streams[file].done = true;
    if (leftover) {
      handleLogLine(file, leftover, opts, stylize);
      leftover = '';
    } else {
      emitNextRecord(opts, stylize);
    }
    callback();
  });
}


/**
 * From node async module.
 */
function asyncForEach(arr, iterator, callback) {
    callback = callback || function () {};
    if (!arr.length) {
        return callback();
    }
    var completed = 0;
    arr.forEach(function (x) {
        iterator(x, function (err) {
            if (err) {
                callback(err);
                callback = function () {};
            }
            else {
                completed += 1;
                if (completed === arr.length) {
                    callback();
                }
            }
        });
    });
};



/**
 * Cleanup and exit properly.
 *
 * Warning: this doesn't stop processing, i.e. process exit might be delayed.
 * It is up to the caller to ensure that no subsequent bunyan processing
 * is done after calling this.
 *
 * @param code {Number} exit code.
 * @param signal {String} Optional signal name, if this was exitting because
 *    of a signal.
 */
var cleanedUp = false;
function cleanupAndExit(code, signal) {
  // Guard one call.
  if (cleanedUp) {
    return;
  }
  cleanedUp = true;
  if (_DEBUG) warn('(bunyan: cleanupAndExit)');

  // Clear possibly interrupted ANSI code (issue #59).
  if (usingAnsiCodes) {
    stdout.write('\033[0m');
  }

  // Kill possible dtrace child.
  if (child) {
    child.kill(signal);
  }

  if (pager) {
    // Let pager know that output is done, then wait for pager to exit.
    stdout.end();
    pager.on('exit', function (pagerCode) {
      if (_DEBUG)
        warn('(bunyan: pager exit -> process.exit(%s))', pagerCode || code);
      process.exit(pagerCode || code);
    });
  } else {
    if (_DEBUG) warn('(bunyan: process.exit(%s))', code);
    process.exit(code);
  }
}



//---- mainline

process.on('SIGINT', function () { cleanupAndExit(1, 'SIGINT'); });
process.on('SIGQUIT', function () { cleanupAndExit(1, 'SIGQUIT'); });
process.on('SIGTERM', function () { cleanupAndExit(1, 'SIGTERM'); });
process.on('SIGHUP', function () { cleanupAndExit(1, 'SIGHUP'); });

process.on('uncaughtException', function (err) {
  function _indent(s) {
    var lines = s.split(/\r?\n/);
    for (var i = 0; i < lines.length; i++) {
      lines[i] = '*     ' + lines[i];
    }
    return lines.join('\n');
  }

  var title = encodeURIComponent(format(
    "Bunyan %s crashed: %s", getVersion(), String(err)));
  console.error('* * *');
  console.error('* The Bunyan CLI crashed!');
  console.error('*');
  if (err.name === 'ReferenceError' && gOptsForUncaughtException.conditions) {
    console.error('* A "ReferenceError" is often the result of given');
    console.error('* `-c CONDITION` code that doesn\'t guard against undefined');
    console.error('* values. If that is not the problem:');
    console.error('*');
  }
  console.error('* Please report this issue and include the details below:');
  console.error('*');
  console.error('*    https://github.com/trentm/node-bunyan/issues/new?title=%s', title);
  console.error('*');
  console.error('* * *');
  console.error('* node version:', process.version);
  console.error('* bunyan version:', getVersion());
  console.error('* argv: %j', process.argv);
  console.error('* log line: %j', currLine);
  console.error('* stack:');
  console.error(_indent(err.stack));
  console.error('* * *');
  process.exit(1);
});


function main(argv) {
  try {
    var opts = parseArgv(argv);
  } catch (e) {
    warn("bunyan: error: %s", e.message);
    return drainStdoutAndExit(1);
  }
  gOptsForUncaughtException = opts; // intentionally global
  if (opts.help) {
    printHelp();
    return;
  }
  if (opts.version) {
    console.log("bunyan " + getVersion());
    return;
  }
  if (opts.pid && opts.args.length > 0) {
    warn("bunyan: error: can't use both '-p PID' (%s) and file (%s) args",
      opts.pid, opts.args.join(' '));
    return drainStdoutAndExit(1);
  }
  if (opts.color === null) {
    if (process.env.BUNYAN_NO_COLOR &&
        process.env.BUNYAN_NO_COLOR.length > 0) {
      opts.color = false;
    } else {
      opts.color = process.stdout.isTTY;
    }
  }
  usingAnsiCodes = opts.color; // intentionally global
  var stylize = (opts.color ? stylizeWithColor : stylizeWithoutColor);

  // Pager.
  var nodeVer = process.versions.node.split('.').map(Number);
  var paginate = (process.stdout.isTTY
                  && process.platform !== 'win32'
                  && nodeVer >= [0,8,0]
                  && (opts.paginate === true
                      || (opts.paginate !== false
                          && (!process.env.BUNYAN_NO_PAGER
                              || process.env.BUNYAN_NO_PAGER.length === 0))));
  if (paginate) {
    var pagerCmd = process.env.PAGER || 'less';
    assert.ok(pagerCmd.indexOf('"') === -1 && pagerCmd.indexOf("'") === -1,
      'cannot parse PAGER quotes yet');
    var argv = pagerCmd.split(/\s+/g);
    var env = objCopy(process.env);
    if (env.LESS === undefined) {
      // git's default is LESS=FRSX. I don't like the 'S' here because lines
      // are *typically* wide with bunyan output and scrolling horizontally
      // is a royal pain.
      // Note a bug in Mac's `less -F`, such that SIGWINCH can kill it.
      // If that rears too much then I'll remove 'F' from here.
      env.LESS = 'FRX';
    }
    if (_DEBUG) warn("(pager: argv=%j, env.LESS=%j)", argv, env.LESS);
    // `pager` and `stdout` intentionally global.
    pager = spawn(argv[0], argv.slice(1),
      // Share the stderr handle to have error output come
      // straight through. Only supported in v0.8+.
      {env: env, stdio: ['pipe',1,2]});
    stdout = pager.stdin;

    // Early termination of the pager: just stop.
    pager.on('exit', function (pagerCode) {
      if (_DEBUG) warn('(bunyan: pager exit)');
      pager = null;
      stdout.end()
      stdout = process.stdout;
      cleanupAndExit(pagerCode);
    });
  }

  // Stdout error handling. (Couldn't setup until `stdout` was determined.)
  stdout.on("error", function (err) {
    if (_DEBUG) warn('(stdout error event: %s)', err);
    if (err.code === "EPIPE") {
      drainStdoutAndExit(0);
    } else if (err.toString() === 'Error: This socket is closed.') {
      // Could get this if the pager closes its stdin, but hasn't exited yet.
      drainStdoutAndExit(1);
    } else {
      warn(err);
      drainStdoutAndExit(1);
    }
  });

  var retval = 0;
  if (opts.pids) {
    processPids(opts, stylize, function (code) {
      cleanupAndExit(code);
    });
  } else if (opts.args.length > 0) {
    var files = opts.args;
    files.forEach(function (file) {
      streams[file] = { stream: null, records: [], done: false }
    });
    asyncForEach(files,
      function (file, next) {
        processFile(file, opts, stylize, function (err) {
          if (err) {
            warn('bunyan: %s', err.message);
            retval += 1;
          }
          next();
        });
      },
      function (err) {
        if (err) {
          warn("bunyan: unexpected error: %s", err.stack || err);
          return drainStdoutAndExit(1);
        }
        cleanupAndExit(retval);
      }
    );
  } else {
    processStdin(opts, stylize, function () {
      cleanupAndExit(retval);
    });
  }
}

if (require.main === module) {
  // HACK guard for <https://github.com/trentm/json/issues/24>.
  // We override the `process.stdout.end` guard that core node.js puts in
  // place. The real fix is that `.end()` shouldn't be called on stdout
  // in node core. Node v0.6.9 fixes that. Only guard for v0.6.0..v0.6.8.
  var nodeVer = process.versions.node.split('.').map(Number);
  if ([0,6,0] <= nodeVer && nodeVer <= [0,6,8]) {
    var stdout = process.stdout;
    stdout.end = stdout.destroy = stdout.destroySoon = function() {
      /* pass */
    };
  }

  main(process.argv);
}