From 11e26ecf554440e2b248f934ef1a3f1e6d62f791 Mon Sep 17 00:00:00 2001 From: Trent Mick Date: Wed, 2 Aug 2017 16:48:15 -0700 Subject: [PATCH] Fix the `bunyan` CLI to not duplicate the "HTTP/1.1 ..." status line when serializing a "res" field. (#444) --- CHANGES.md | 3 +- bin/bunyan | 41 ++++++++++++++------ test/cli-res.test.js | 61 ++++++++++++++++++++++++++++++ test/corpus/res-header.log | 1 + test/corpus/res-without-header.log | 1 + 5 files changed, 95 insertions(+), 12 deletions(-) create mode 100644 test/cli-res.test.js create mode 100644 test/corpus/res-header.log create mode 100644 test/corpus/res-without-header.log diff --git a/CHANGES.md b/CHANGES.md index ee035f8..9d3b15b 100644 --- a/CHANGES.md +++ b/CHANGES.md @@ -7,7 +7,8 @@ Known issues: ## not yet released -(nothing yet) +- [issue #444] Fix the `bunyan` CLI to not duplicate the "HTTP/1.1 ..." status + line when serializing a "res" field. ## 2.0.1 (beta) diff --git a/bin/bunyan b/bin/bunyan index cd96878..a745a22 100755 --- a/bin/bunyan +++ b/bin/bunyan @@ -953,17 +953,21 @@ function emitRecord(rec, line, opts, stylize) { function _res(res) { var s = ''; - if (res.statusCode !== undefined) { - s += format('HTTP/1.1 %s %s\n', res.statusCode, - http.STATUS_CODES[res.statusCode]); - delete res.statusCode; - } - // Handle `res.header` or `res.headers` as either a string or - // and object of header key/value pairs. Prefer `res.header` if set - // (TODO: Why? I don't recall. Typical of restify serializer? - // Typical JSON.stringify of a core node HttpResponse?) + + /* + * Handle `res.header` or `res.headers` as either a string or + * an object of header key/value pairs. Prefer `res.header` if set, + * because that's what Bunyan's own `res` serializer specifies, + * because that's the value in Node.js's core HTTP server response + * implementation that has all the implicit headers. + * + * Note: `res.header` (string) typically includes the 'HTTP/1.1 ...' + * status line. + */ var headerTypes = {string: true, object: true}; var headers; + var headersStr = ''; + var headersHaveStatusLine = false; if (res.header && headerTypes[typeof (res.header)]) { headers = res.header; delete res.header; @@ -974,11 +978,26 @@ function emitRecord(rec, line, opts, stylize) { if (headers === undefined) { /* pass through */ } else if (typeof (headers) === 'string') { - s += headers.trimRight(); + headersStr = headers.trimRight(); // Trim the CRLF. + if (headersStr.slice(0, 5) === 'HTTP/') { + headersHaveStatusLine = true; + } } else { - s += Object.keys(headers).map( + headersStr += Object.keys(headers).map( function (h) { return h + ': ' + headers[h]; }).join('\n'); } + + /* + * Add a 'HTTP/1.1 ...' status line if the headers didn't already + * include it. + */ + if (!headersHaveStatusLine && res.statusCode !== undefined) { + s += format('HTTP/1.1 %s %s\n', res.statusCode, + http.STATUS_CODES[res.statusCode]); + } + delete res.statusCode; + s += headersStr; + if (res.body !== undefined) { var body = (typeof (res.body) === 'object' ? JSON.stringify(res.body, null, 2) : res.body); diff --git a/test/cli-res.test.js b/test/cli-res.test.js new file mode 100644 index 0000000..75cb5dd --- /dev/null +++ b/test/cli-res.test.js @@ -0,0 +1,61 @@ +/* + * Copyright (c) 2017, Trent Mick. + * + * Test the bunyan CLI's handling of the "res" field. + */ + +var exec = require('child_process').exec; +var fs = require('fs'); +var path = require('path'); +var _ = require('util').format; +var vasync = require('vasync'); + +// node-tap API +if (require.cache[__dirname + '/tap4nodeunit.js']) + delete require.cache[__dirname + '/tap4nodeunit.js']; +var tap4nodeunit = require('./tap4nodeunit.js'); +var after = tap4nodeunit.after; +var before = tap4nodeunit.before; +var test = tap4nodeunit.test; + + +// ---- globals + +var BUNYAN = path.resolve(__dirname, '../bin/bunyan'); + + +// ---- tests + +test('res with "header" string (issue #444)', function (t) { + var expect = [ + /* BEGIN JSSTYLED */ + '[2017-08-02T22:37:34.798Z] INFO: res-header/76488 on danger0.local: response sent', + ' HTTP/1.1 200 OK', + ' Foo: bar', + ' Date: Wed, 02 Aug 2017 22:37:34 GMT', + ' Connection: keep-alive', + ' Content-Length: 21' + /* END JSSTYLED */ + ].join('\n') + '\n'; + exec(_('%s %s/corpus/res-header.log', BUNYAN, __dirname), + function (err, stdout, stderr) { + t.ifError(err); + t.equal(stdout, expect); + t.end(); + }); +}); + +test('res without "header"', function (t) { + var expect = [ + /* BEGIN JSSTYLED */ + '[2017-08-02T22:37:34.798Z] INFO: res-header/76488 on danger0.local: response sent', + ' HTTP/1.1 200 OK' + /* END JSSTYLED */ + ].join('\n') + '\n'; + exec(_('%s %s/corpus/res-without-header.log', BUNYAN, __dirname), + function (err, stdout, stderr) { + t.ifError(err); + t.equal(stdout, expect); + t.end(); + }); +}); diff --git a/test/corpus/res-header.log b/test/corpus/res-header.log new file mode 100644 index 0000000..aa47314 --- /dev/null +++ b/test/corpus/res-header.log @@ -0,0 +1 @@ +{"name":"res-header","hostname":"danger0.local","pid":76488,"level":30,"res":{"statusCode":200,"header":"HTTP/1.1 200 OK\r\nFoo: bar\r\nDate: Wed, 02 Aug 2017 22:37:34 GMT\r\nConnection: keep-alive\r\nContent-Length: 21\r\n\r\n"},"msg":"response sent","time":"2017-08-02T22:37:34.798Z","v":0} diff --git a/test/corpus/res-without-header.log b/test/corpus/res-without-header.log new file mode 100644 index 0000000..eebcee2 --- /dev/null +++ b/test/corpus/res-without-header.log @@ -0,0 +1 @@ +{"name":"res-header","hostname":"danger0.local","pid":76488,"level":30,"res":{"statusCode":200},"msg":"response sent","time":"2017-08-02T22:37:34.798Z","v":0}