From 2d17313c4a0324c594067a6abe314c33d6e5844e Mon Sep 17 00:00:00 2001 From: Trent Mick Date: Wed, 2 Aug 2017 13:20:42 -0700 Subject: [PATCH] cli: don't guess at a Host header when rendering client_req field (#504) --- CHANGES.md | 7 ++- bin/bunyan | 18 +++---- test/cli-client-req.test.js | 68 +++++++++++++++++++++++++ test/cli.test.js | 18 ------- test/corpus/client-req-with-address.log | 1 + 5 files changed, 81 insertions(+), 31 deletions(-) create mode 100644 test/cli-client-req.test.js create mode 100644 test/corpus/client-req-with-address.log diff --git a/CHANGES.md b/CHANGES.md index 8542285..39936d7 100644 --- a/CHANGES.md +++ b/CHANGES.md @@ -7,7 +7,12 @@ Known issues: ## not yet released -(nothing yet) +- [issue #504] **Backward incompatible change to the `bunyan` CLI:** + The `bunyan` CLI no longer adds a `Host` header when rendering a `client_req` + field in a log record. In 1.x it used to do this (using `client_req.address` + and `client_req.port`), on the *guess* that Node.js' `http.ClientRequest` + handling would add it. However, the guess can be wrong and misleading. It is + better not to guess. ## 2.0.0 (beta) diff --git a/bin/bunyan b/bin/bunyan index df341f8..3275b24 100755 --- a/bin/bunyan +++ b/bin/bunyan @@ -918,21 +918,14 @@ function emitRecord(rec, line, opts, stylize) { 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 = '\nHost: ' + client_req.address; - if (client_req.port) - hostHeaderLine += ':' + client_req.port; - } delete client_req.headers; - delete client_req.address; - delete client_req.port; - s += format('%s %s HTTP/%s%s%s', client_req.method, + + var s = format('%s %s HTTP/%s%s', + client_req.method, client_req.url, client_req.httpVersion || '1.1', - hostHeaderLine, (headers ? '\n' + Object.keys(headers).map( function (h) { @@ -942,6 +935,7 @@ function emitRecord(rec, line, opts, stylize) { 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) : @@ -953,7 +947,7 @@ function emitRecord(rec, line, opts, stylize) { // 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)); } diff --git a/test/cli-client-req.test.js b/test/cli-client-req.test.js new file mode 100644 index 0000000..9ed6476 --- /dev/null +++ b/test/cli-client-req.test.js @@ -0,0 +1,68 @@ +/* + * Copyright (c) 2017, Trent Mick. + * + * Test the bunyan CLI's handling of the "client_req" field. + * "client_req" is a common-ish Bunyan log field from restify-clients. See: + * // JSSTYLED + * https://github.com/restify/clients/blob/85374f87db9f4469de2605b6b15632b317cc12be/lib/helpers/bunyan.js#L213 + */ + +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('client_req extra newlines, client_res={} (pull #252)', function (t) { + var expect = [ + /* BEGIN JSSTYLED */ + '[2016-02-10T07:28:40.510Z] TRACE: aclientreq/23280 on danger0.local: request sent', + ' GET /--ping HTTP/1.1', + '[2016-02-10T07:28:41.419Z] TRACE: aclientreq/23280 on danger0.local: Response received', + ' HTTP/1.1 200 OK', + ' request-id: e8a5a700-cfc7-11e5-a3dc-3b85d20f26ef', + ' content-type: application/json' + /* END JSSTYLED */ + ].join('\n') + '\n'; + exec(_('%s %s/corpus/clientreqres.log', BUNYAN, __dirname), + function (err, stdout, stderr) { + t.ifError(err); + t.equal(stdout, expect); + t.end(); + }); +}); + + +test('client_req.address is not used for Host header in 2.x (issue #504)', + function (t) { + exec(_('%s %s/corpus/client-req-with-address.log', BUNYAN, __dirname), + function (err, stdout, stderr) { + t.ifError(err) + t.equal(stdout, [ + // JSSTYLED: + '[2017-05-12T23:59:15.877Z] TRACE: minfo/66266 on sharptooth.local: request sent (client_req.address=127.0.0.1)', + ' HEAD /dap/stor HTTP/1.1', + ' accept: application/json, */*', + ' host: foo.example.com', + ' date: Fri, 12 May 2017 23:59:15 GMT', + '' + ].join('\n')); + t.end(); + }); +}); diff --git a/test/cli.test.js b/test/cli.test.js index 99ba9b9..5ba4e0f 100644 --- a/test/cli.test.js +++ b/test/cli.test.js @@ -484,24 +484,6 @@ test('should not crash on corpus/old-crashers/*.log', function (t) { }); }); -test('client_req extra newlines, client_res={} (pull #252)', function (t) { - var expect = [ - /* BEGIN JSSTYLED */ - '[2016-02-10T07:28:40.510Z] TRACE: aclientreq/23280 on danger0.local: request sent', - ' GET /--ping HTTP/1.1', - '[2016-02-10T07:28:41.419Z] TRACE: aclientreq/23280 on danger0.local: Response received', - ' HTTP/1.1 200 OK', - ' request-id: e8a5a700-cfc7-11e5-a3dc-3b85d20f26ef', - ' content-type: application/json' - /* END JSSTYLED */ - ].join('\n') + '\n'; - exec(_('%s %s/corpus/clientreqres.log', BUNYAN, __dirname), - function (err, stdout, stderr) { - t.ifError(err); - t.equal(stdout, expect); - t.end(); - }); -}); test('should only show nonempty response bodies', function (t) { var expect = [ diff --git a/test/corpus/client-req-with-address.log b/test/corpus/client-req-with-address.log new file mode 100644 index 0000000..cceb8dd --- /dev/null +++ b/test/corpus/client-req-with-address.log @@ -0,0 +1 @@ +{"name":"minfo","hostname":"sharptooth.local","pid":66266,"level":10,"client_req":{"method":"HEAD","url":"/dap/stor","address":"127.0.0.1","headers":{"accept":"application/json, */*","host":"foo.example.com","date":"Fri, 12 May 2017 23:59:15 GMT"}},"msg":"request sent","time":"2017-05-12T23:59:15.877Z","v":0}