[issue #34] body et al in request/response output by bunyan CLI

Ensure `req.body`, `res.body` and other request/response
fields are emitted by the `bunyan` CLI (mostly by Rob Gulewich).

AUTHORS

@@ -3,3 +3,4 @@ Mark Cavage <mcavage@gmail.com> (https://github.com/mcavage)
 Dave Pacheco <dap@joyent.com> (https://github.com/davepacheco)
 Michael Hart (https://github.com/mhart)
 Isaac Schlueter (https://github.com/isaacs)
+Rob Gulewich (https://github.com/rgulewich)

CHANGES.md

@@ -2,7 +2,9 @@
 
 ## bunyan 0.13.1 (not yet released)
 
-(nothing yet)
+- [issue #34] Ensure `req.body`, `res.body` and other request/response fields
+  are emitted by the `bunyan` CLI (mostly by Rob Gulewich).
+
 
 
 ## bunyan 0.13.0

Makefile

@@ -36,24 +36,27 @@ test: $(TAP)
 
 # Test will all node supported versions (presumes install locations I use on my machine).
 .PHONY: testall
-testall: test06 test07 testmaster
+testall: test08 test06 test09 testmaster
 
 .PHONY: testmaster
 testmaster:
 	@echo "# Test node master (with node `$(HOME)/opt/node-master/bin/node --version`)"
 	PATH="$(HOME)/opt/node-master/bin:$(PATH)" TAP=1 $(TAP) test/*.test.js
-
+.PHONY: test09
-.PHONY: test07
+test09:
-test07:
+	@echo "# Test node 0.9.x (with node `$(HOME)/opt/node-0.9/bin/node --version`)"
-	@echo "# Test node 0.7.x (with node `$(HOME)/opt/node-0.7/bin/node --version`)"
+	PATH="$(HOME)/opt/node-0.9/bin:$(PATH)" TAP=1 $(TAP) test/*.test.js
-	PATH="$(HOME)/opt/node-0.7/bin:$(PATH)" TAP=1 $(TAP) test/*.test.js
+.PHONY: test08
-
+test08:
+	@echo "# Test node 0.8.x (with node `$(HOME)/opt/node-0.8/bin/node --version`)"
+	PATH="$(HOME)/opt/node-0.8/bin:$(PATH)" TAP=1 $(TAP) test/*.test.js
 .PHONY: test06
 test06:
 	@echo "# Test node 0.6.x (with node `$(HOME)/opt/node-0.6/bin/node --version`)"
 	PATH="$(HOME)/opt/node-0.6/bin:$(PATH)" TAP=1 $(TAP) test/*.test.js
 
 
+
 #---- check
 
 .PHONY: check-jsstyle

bin/bunyan

@@ -613,50 +613,108 @@ function emitRecord(rec, line, opts, stylize) {
     delete rec.msg;
 
     if (rec.req) {
-      var headers = rec.req.headers;
+      var req = rec.req;
-      details.push(indent(format("%s %s HTTP/1.1%s", rec.req.method,
+      var headers = req.headers;
-        rec.req.url,
+      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' + 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];
+      })
     }
     delete rec.req;
 
     if (rec.client_req) {
-      var headers = rec.client_req.headers;
+      var client_req = rec.client_req;
+      var headers = client_req.headers;
       var hostHeaderLine = '';
-      if (rec.client_req.address) {
+      var s = '';
-        hostHeaderLine = 'Host: ' + rec.client_req.address;
+      if (client_req.address) {
-        if (rec.client_req.port)
+        hostHeaderLine = 'Host: ' + client_req.address;
-          hostHeaderLine += ':' + rec.client_req.port;
+        if (client_req.port)
+          hostHeaderLine += ':' + client_req.port;
         hostHeaderLine += '\n';
       }
-      details.push(indent(format("%s %s HTTP/1.1\n%s%s", rec.client_req.method,
+      delete client_req.headers;
-        rec.client_req.url,
+      delete client_req.address;
+      delete client_req.port;
+      s += format("%s %s HTTP/%s\n%s%s", client_req.method,
+        client_req.url,
+        req.client_req.httpVersion || "1.1",
         hostHeaderLine,
         Object.keys(headers).map(
-          function (h) { return h + ': ' + headers[h]; }).join('\n'))));
+          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' + 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));
     }
     delete rec.client_req;
 
     if (rec.res) {
+      var res = rec.res;
       var s = '';
-      if (rec.res.header) {
+      if (res.header) {
-        s += rec.res.header.trimRight();
+        s += res.header.trimRight();
-      } else if (rec.res.headers) {
+      } else if (res.headers) {
-        if (rec.res.statusCode) {
+        if (res.statusCode) {
-          s += format("HTTP/1.1 %s %s\n", rec.res.statusCode,
+          s += format("HTTP/1.1 %s %s\n", res.statusCode,
-            http.STATUS_CODES[rec.res.statusCode]);
+            http.STATUS_CODES[res.statusCode]);
         }
-        var headers = rec.res.headers;
+        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' + 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];
+      })
     }
     delete rec.res;
 

test/cli.test.js

@@ -33,7 +33,7 @@ test('--version', function (t) {
 test('--help', function (t) {
   exec(BUNYAN + ' --help', function (err, stdout, stderr) {
     t.error(err)
-    t.ok(stdout.indexOf('Options:') !== -1);
+    t.ok(stdout.indexOf('General options:') !== -1);
     t.end();
   });
 });
@@ -41,7 +41,7 @@ test('--help', function (t) {
 test('-h', function (t) {
   exec(BUNYAN + ' -h', function (err, stdout, stderr) {
     t.error(err)
-    t.ok(stdout.indexOf('Options:') !== -1);
+    t.ok(stdout.indexOf('General options:') !== -1);
     t.end();
   });
 });
@@ -279,7 +279,7 @@ test('multiple --conditions', function (t) {
 test('robust req handling', function (t) {
   var expect = [
     '[2012-08-08T10:25:47.636Z] DEBUG: amon-master/12859 on 9724a190-27b6-4fd8-830b-a574f839c67d: headAgentProbes respond (req_id=cce79d15-ffc2-487c-a4e4-e940bdaac31e, route=HeadAgentProbes, contentMD5=11FxOYiYfpMxmANj4kGJzg==)',
-    '[2012-08-08T10:25:47.637Z]  INFO: amon-master/12859 on 9724a190-27b6-4fd8-830b-a574f839c67d: HeadAgentProbes handled: 200 (req_id=cce79d15-ffc2-487c-a4e4-e940bdaac31e, 3ms, audit=true, remoteAddress=10.2.207.2, remotePort=50394, secure=false, _audit=true)',
+    '[2012-08-08T10:25:47.637Z]  INFO: amon-master/12859 on 9724a190-27b6-4fd8-830b-a574f839c67d: HeadAgentProbes handled: 200 (req_id=cce79d15-ffc2-487c-a4e4-e940bdaac31e, 3ms, audit=true, remoteAddress=10.2.207.2, remotePort=50394, secure=false, _audit=true, req.version=*)',
     '    HEAD /agentprobes?agent=ccf92af9-0b24-46b6-ab60-65095fdd3037 HTTP/1.1',
     '    accept: application/json',
     '    content-type: application/json',
@@ -302,7 +302,7 @@ test('robust req handling', function (t) {
     '      "name": "HeadAgentProbes",',
     '      "version": false',
     '    }',
-    '[2012-08-08T10:25:47.637Z]  INFO: amon-master/12859 on 9724a190-27b6-4fd8-830b-a574f839c67d: HeadAgentProbes handled: 200 (req_id=cce79d15-ffc2-487c-a4e4-e940bdaac31e, 3ms, audit=true, remoteAddress=10.2.207.2, remotePort=50394, secure=false, _audit=true)',
+    '[2012-08-08T10:25:47.637Z]  INFO: amon-master/12859 on 9724a190-27b6-4fd8-830b-a574f839c67d: HeadAgentProbes handled: 200 (req_id=cce79d15-ffc2-487c-a4e4-e940bdaac31e, 3ms, audit=true, remoteAddress=10.2.207.2, remotePort=50394, secure=false, _audit=true, req.version=*)',
     '    HEAD /agentprobes?agent=ccf92af9-0b24-46b6-ab60-65095fdd3037 HTTP/1.1',
     '    --',
     '    route: {',