diff --git a/grunt/config/mochacov.js b/grunt/config/mochacov.js index 125aee03b..27b6d7c30 100644 --- a/grunt/config/mochacov.js +++ b/grunt/config/mochacov.js @@ -1,6 +1,6 @@ module.exports = { unit: { - src: 'test/unit' + src: 'test/unit/index.js' }, integration_master: { diff --git a/scripts/ci.sh b/scripts/ci.sh index db0c98b18..68b2741d6 100755 --- a/scripts/ci.sh +++ b/scripts/ci.sh @@ -31,7 +31,7 @@ fi if [[ "$NODE_UNIT" != "0" ]]; then group "running unit tests" if [[ -n "$JENKINS" ]]; then - $MOCHA test/unit/tests/*.js --reporter $MOCHA_REPORTER 2> test/junit-node-unit.xml + $MOCHA test/unit/index.js --reporter $MOCHA_REPORTER 2> test/junit-node-unit.xml if [ "$?" -gt "0" ]; then echo "non-zero exit code: $RESULT" cat test/junit-node-unit.xml diff --git a/src/elasticsearch b/src/elasticsearch index 95bf091dd..aadcfa7b5 160000 --- a/src/elasticsearch +++ b/src/elasticsearch @@ -1 +1 @@ -Subproject commit 95bf091dd60ea41f2e269425433481986101035e +Subproject commit aadcfa7b515a9890ea136569db8c15b645ff8cd7 diff --git a/src/lib/log.js b/src/lib/log.js index 448a453e7..c749ae7ea 100755 --- a/src/lib/log.js +++ b/src/lib/log.js @@ -269,45 +269,32 @@ Log.prototype.debug = function (/* ...msg */) { */ Log.prototype.trace = function (method, requestUrl, body, responseBody, responseStatus) { if (this.listenerCount('trace')) { - if (typeof requestUrl === 'string') { - requestUrl = url.parse(requestUrl, true, true); - } else if (requestUrl.path) { - requestUrl.query = url.parse(requestUrl.path, true, false).query; - } - - requestUrl = _.defaults({ - host: 'localhost:9200', - query: _.defaults(requestUrl.query || {}, { - pretty: true - }) - }, requestUrl); - delete requestUrl.auth; - - if (!requestUrl.pathname && requestUrl.path) { - requestUrl.pathname = requestUrl.path.split('?').shift(); - } - - requestUrl = url.format(requestUrl); - - var message = '<- ' + responseStatus + '\n' + prettyJSON(responseBody); - - /* jshint quotmark: double */ - var curlCall = "curl '" + requestUrl.replace(/'/g, "\\'") + "' -X" + method.toUpperCase(); - if (body) { - curlCall += " -d '" + prettyJSON(body) + "'"; - } - /* jshint quotmark: single */ - - return this.emit('trace', message, curlCall); + return this.emit('trace', Log.normalizeTraceArgs(method, requestUrl, body, responseBody, responseStatus)); } }; -function prettyJSON(body) { - try { - return JSON.stringify(JSON.parse(body), null, ' ').replace(/'/g, '\\u0027'); - } catch (e) { - return body || ''; +Log.normalizeTraceArgs = function (method, requestUrl, body, responseBody, responseStatus) { + if (typeof requestUrl === 'string') { + requestUrl = url.parse(requestUrl, true, true); + } else { + requestUrl = _.clone(requestUrl); + if (requestUrl.path) { + requestUrl.query = url.parse(requestUrl.path, true, false).query; + } + if (!requestUrl.pathname && requestUrl.path) { + requestUrl.pathname = requestUrl.path.split('?').shift(); + } } -} + + delete requestUrl.auth; + + return { + method: method, + url: url.format(requestUrl), + body: body, + status: responseStatus, + response: responseBody + }; +}; module.exports = Log; diff --git a/src/lib/logger.js b/src/lib/logger.js index df380d74e..adf8dadb6 100644 --- a/src/lib/logger.js +++ b/src/lib/logger.js @@ -38,7 +38,7 @@ LoggerAbstract.prototype.timestamp = function () { function indent(text, spaces) { var space = _.repeat(' ', spaces || 2); - return text.split(/\r?\n/).map(function (line) { + return (text || '').split(/\r?\n/).map(function (line) { return space + line; }).join('\n'); } @@ -144,9 +144,37 @@ LoggerAbstract.prototype.onDebug = _.handler(function (msg) { * @param {String} msg - The message to be logged * @return {undefined} */ -LoggerAbstract.prototype.onTrace = _.handler(function (message, curlCall) { - this.write('TRACE', curlCall + '\n' + message); +LoggerAbstract.prototype.onTrace = _.handler(function (requestDetails) { + this.write('TRACE', this._formatTraceMessage(requestDetails)); }); +LoggerAbstract.prototype._formatTraceMessage = function (req) { + return '-> ' + req.method + ' ' + req.url + '\n' + + this._prettyJson(req.body) + '\n' + + '<- ' + req.status + '\n' + + this._prettyJson(req.response); +/* +-> GET https://sldfkjsdlfksjdf:9200/slsdkfjlxckvxhclks?sdlkj=sdlfkje +{ + asdflksjdf +} + +<- 502 +{ + sldfksjdlf +} +*/ +}; + +LoggerAbstract.prototype._prettyJson = function (body) { + try { + if (typeof object === 'string') { + body = JSON.parse(body); + } + return JSON.stringify(body, null, ' ').replace(/'/g, '\\u0027'); + } catch (e) { + return typeof body === 'string' ? body : ''; + } +}; module.exports = LoggerAbstract; diff --git a/src/lib/loggers/console.js b/src/lib/loggers/console.js index 7d6571a44..d5ec9771f 100644 --- a/src/lib/loggers/console.js +++ b/src/lib/loggers/console.js @@ -94,6 +94,6 @@ Console.prototype.onDebug = _.handler(function (msg) { * @private * @return {undefined} */ -Console.prototype.onTrace = _.handler(function (msg, curlCall) { - this.write('TRACE', curlCall + '\n' + msg, 'log'); +Console.prototype.onTrace = _.handler(function (msg) { + this.write('TRACE', this._formatTraceMessage(msg), 'log'); }); diff --git a/src/lib/loggers/stdio.js b/src/lib/loggers/stdio.js index 67664d20c..1ba868d33 100755 --- a/src/lib/loggers/stdio.js +++ b/src/lib/loggers/stdio.js @@ -112,6 +112,6 @@ Stdio.prototype.onDebug = _.handler(function (msg) { * @private * @return {undefined} */ -Stdio.prototype.onTrace = _.handler(function (message, curlCall) { - this.write('TRACE', curlCall + '\n' + message, process.stdout, this.colors.trace); +Stdio.prototype.onTrace = _.handler(function (message) { + this.write('TRACE', this._formatTraceMessage(message), process.stdout, this.colors.trace); }); diff --git a/src/lib/loggers/tracer.js b/src/lib/loggers/tracer.js index e37edd0dc..bedaf2807 100755 --- a/src/lib/loggers/tracer.js +++ b/src/lib/loggers/tracer.js @@ -15,6 +15,7 @@ module.exports = Tracer; var StreamLogger = require('./stream'); var fs = require('fs'); var _ = require('../utils'); +var url = require('url'); function Tracer(log, config) { if (config.path === false) { @@ -23,13 +24,36 @@ function Tracer(log, config) { config.stream = fs.createWriteStream(config.path || 'elasticsearch-tracer.log'); } + this.curlHost = config.curlHost || 'localhost'; + this.curlPort = config.curlPort || 9200; + StreamLogger.call(this, log, config); } _.inherits(Tracer, StreamLogger); -Tracer.prototype.onTrace = _.handler(function (message, curlCall) { - this.write('TRACE', message, curlCall); -}); +var usefulUrlFields = ['protocol', 'slashes', 'port', 'hostname', 'pathname', 'query']; + +Tracer.prototype._formatTraceMessage = function (req) { + var reqUrl = _.pick(url.parse(req.url, true, false), usefulUrlFields); + + var originalHost = url.format(_.pick(reqUrl, 'protocol', 'hostname', 'port')); + + reqUrl.port = this.curlPort; + reqUrl.host = this.curlHost; + reqUrl.query = _.defaults(reqUrl.query || {}, { pretty: true }); + + /* jshint quotmark: double */ + var curlCall = + "# " + originalHost + "\n" + + "curl '" + url.format(reqUrl).replace(/'/g, "\\'") + "' -X" + req.method.toUpperCase() + + (req.body ? " -d '" + this._prettyJson(req.body) + "'" : ""); + /* jshint quotmark: single */ + + return { + curl: curlCall, + msg: '-> ' + req.status + '\n' + req.response + }; +}; function comment(str) { return _.map(str.split(/\r?\n/g), function (line) { @@ -37,10 +61,11 @@ function comment(str) { }).join('\n'); } -Tracer.prototype.write = function (label, message, curlCall) { - this.stream.write( - comment(label + ': ' + this.timestamp()) + '\n' + (curlCall ? curlCall + '\n' : '') + - comment(message) + '\n\n', - 'utf8' - ); +Tracer.prototype.write = function (label, msg) { + var lead = comment(label + ': ' + this.timestamp()) + '\n'; + if (typeof msg === 'string') { + this.stream.write(lead + comment(msg) + '\n\n', 'utf8'); + } else { + this.stream.write(lead + msg.curl + '\n' + comment(msg.msg) + '\n\n', 'utf8'); + } }; diff --git a/test/unit/browser.js b/test/unit/browser.js new file mode 100644 index 000000000..aa1fe18ef --- /dev/null +++ b/test/unit/browser.js @@ -0,0 +1,16 @@ +var exclude = [ + 'file_logger.js', + 'http_connector.js', + 'stdio_logger.js', + 'console_logger.js', + 'stream_logger.js', + 'tracer_logger.js', + 'transport_with_server.js' +]; + +var _ = require('lodash'); +var specDir = __dirname + '/specs'; + +_(require('fs').readdirSync(specDir)).difference(exclude).each(function (file) { + require(specDir + '/' + file); +}); \ No newline at end of file diff --git a/test/unit/browser_builds/index.js b/test/unit/browser_builds/index.js new file mode 100644 index 000000000..d5c61dbab --- /dev/null +++ b/test/unit/browser_builds/index.js @@ -0,0 +1,3 @@ +require('./angular'); +require('./generic'); +require('./jquery'); \ No newline at end of file diff --git a/test/unit/generic_logger_tests.js b/test/unit/generic_logger_tests.js index d7c12c756..f9f3ed834 100644 --- a/test/unit/generic_logger_tests.js +++ b/test/unit/generic_logger_tests.js @@ -230,22 +230,8 @@ module.exports = function (makeLogger) { stub(logger, 'write', function (label, msg) { expect(label).to.eql('TRACE'); }); - logger.onTrace('message'); + logger.onTrace(Log.normalizeTraceArgs('GET', 'http://place/thing?me=true', '{}', '{"ok": true}', 200)); expect(logger.write.callCount).to.eql(1); }); - - it('joins the message and curl call with a newline', function () { - var logger = makeLogger(); - - // tracer logger has custom trace logic... - if (!(logger instanceof TracerLogger)) { - stub(logger, 'write', function (label, msg) { - expect(msg).to.eql('curlcall\nmessage'); - }); - - logger.onTrace('message', 'curlcall'); - expect(logger.write.callCount).to.eql(1); - } - }); }); }; \ No newline at end of file diff --git a/test/unit/index.js b/test/unit/index.js index 2acb3d2e7..b0f91a4b4 100644 --- a/test/unit/index.js +++ b/test/unit/index.js @@ -1,3 +1,5 @@ -require('fs').readdirSync(__dirname + '/tests').forEach(function (file) { - require(__dirname + '/tests/' + file); +var specDir = __dirname + '/specs'; + +require('fs').readdirSync(specDir).forEach(function (file) { + require(specDir + '/' + file); }); \ No newline at end of file diff --git a/test/unit/tests/abstract_logger.js b/test/unit/specs/abstract_logger.js similarity index 100% rename from test/unit/tests/abstract_logger.js rename to test/unit/specs/abstract_logger.js diff --git a/test/unit/tests/client.js b/test/unit/specs/client.js similarity index 100% rename from test/unit/tests/client.js rename to test/unit/specs/client.js diff --git a/test/unit/tests/client_action.js b/test/unit/specs/client_action.js similarity index 100% rename from test/unit/tests/client_action.js rename to test/unit/specs/client_action.js diff --git a/test/unit/tests/connection_abstract.js b/test/unit/specs/connection_abstract.js similarity index 100% rename from test/unit/tests/connection_abstract.js rename to test/unit/specs/connection_abstract.js diff --git a/test/unit/tests/connection_pool.js b/test/unit/specs/connection_pool.js similarity index 100% rename from test/unit/tests/connection_pool.js rename to test/unit/specs/connection_pool.js diff --git a/test/unit/tests/console_logger.js b/test/unit/specs/console_logger.js similarity index 100% rename from test/unit/tests/console_logger.js rename to test/unit/specs/console_logger.js diff --git a/test/unit/tests/errors.js b/test/unit/specs/errors.js similarity index 100% rename from test/unit/tests/errors.js rename to test/unit/specs/errors.js diff --git a/test/unit/tests/file_logger.js b/test/unit/specs/file_logger.js similarity index 100% rename from test/unit/tests/file_logger.js rename to test/unit/specs/file_logger.js diff --git a/test/unit/tests/host.js b/test/unit/specs/host.js similarity index 100% rename from test/unit/tests/host.js rename to test/unit/specs/host.js diff --git a/test/unit/tests/http_connector.js b/test/unit/specs/http_connector.js similarity index 100% rename from test/unit/tests/http_connector.js rename to test/unit/specs/http_connector.js diff --git a/test/unit/tests/json_serializer.js b/test/unit/specs/json_serializer.js similarity index 100% rename from test/unit/tests/json_serializer.js rename to test/unit/specs/json_serializer.js diff --git a/test/unit/tests/log.js b/test/unit/specs/log.js similarity index 95% rename from test/unit/tests/log.js rename to test/unit/specs/log.js index 4925ac55a..8976c01bd 100644 --- a/test/unit/tests/log.js +++ b/test/unit/specs/log.js @@ -182,12 +182,13 @@ describe('Log class', function () { expect(call.args[0]).to.eql('here'); }); - it('should emit a trace event for trace events, with message and curlCall args', function () { + it('should emit a trace event for trace events, with normalized request details arg', function () { log.trace('GET', 'http://localhost:9200/_cluster/nodes', '', '', 200); expect(call.event).to.eql('trace'); - expect(call.args.length).to.be(2); - expect(call.args[0]).to.match(/^<- 200/); - expect(call.args[1]).to.match(/^curl /); + expect(call.args.length).to.be(1); + expect(call.args[0]).to.have.property('method', 'GET'); + expect(call.args[0]).to.have.property('url', 'http://localhost:9200/_cluster/nodes'); + expect(call.args[0]).to.have.property('status', 200); }); }); diff --git a/test/unit/tests/nodes_to_host_callback.js b/test/unit/specs/nodes_to_host_callback.js similarity index 100% rename from test/unit/tests/nodes_to_host_callback.js rename to test/unit/specs/nodes_to_host_callback.js diff --git a/test/unit/tests/random_selector.js b/test/unit/specs/random_selector.js similarity index 100% rename from test/unit/tests/random_selector.js rename to test/unit/specs/random_selector.js diff --git a/test/unit/tests/round_robin_selector.js b/test/unit/specs/round_robin_selector.js similarity index 100% rename from test/unit/tests/round_robin_selector.js rename to test/unit/specs/round_robin_selector.js diff --git a/test/unit/tests/stdio_logger.js b/test/unit/specs/stdio_logger.js similarity index 94% rename from test/unit/tests/stdio_logger.js rename to test/unit/specs/stdio_logger.js index 7f3fb781b..6e4d5c833 100644 --- a/test/unit/tests/stdio_logger.js +++ b/test/unit/specs/stdio_logger.js @@ -57,10 +57,10 @@ describe('Stdio Logger', function () { var logger = makeLogger(); stub(process.stdout, 'write'); - var withoutColor = 'Elasticsearch TRACE: ' + now + '\n curl\n msg\n\n'; + var withoutColor = 'Elasticsearch DEBUG: ' + now + '\n be weary\n\n'; logger.color = true; - logger.onTrace('msg', 'curl'); + logger.onDebug('be weary'); expect(process.stdout.write.lastCall.args[0]).to.not.eql(withoutColor); expect(chalk.stripColor(process.stdout.write.lastCall.args[0])).to.eql(withoutColor); }); diff --git a/test/unit/tests/stream_logger.js b/test/unit/specs/stream_logger.js similarity index 100% rename from test/unit/tests/stream_logger.js rename to test/unit/specs/stream_logger.js diff --git a/test/unit/specs/tracer_logger.js b/test/unit/specs/tracer_logger.js new file mode 100644 index 000000000..d78269c11 --- /dev/null +++ b/test/unit/specs/tracer_logger.js @@ -0,0 +1,74 @@ +describe('Tracer Logger', function () { + + var Log = require('../../../src/lib/log'); + var TracerLogger = require('../../../src/lib/loggers/tracer'); + var sinon = require('sinon'); + var expect = require('expect.js'); + var parentLog; + + beforeEach(function () { + parentLog = new Log(); + }); + + afterEach(function () { + parentLog.close(); + }); + + function makeLogger(parent, levels) { + parent = parent || parentLog; + var config = { + levels: Log.parseLevels(levels || 'trace') + }; + return new TracerLogger(parent, config); + } + + var stub = require('../../utils/auto_release_stub').make(); + + // require('../generic_logger_tests')(makeLogger); + + describe('#formatTraceMessage', function () { + it('includes the original host', function () { + var logger = makeLogger(); + + var formatted = logger._formatTraceMessage({ + method: 'DELETE', + url: 'https://originalHost.com:9522/path/to/thing?qs=100', + body: '{ "yes": true }', + status: 333, + response: '{ "ok": false }' + }); + + expect(formatted.curl).to.match(/-XDELETE/); + expect(formatted.curl).to.match(/https:\/\/originalHost\.com:9522\/?\s+/i); + expect(formatted.curl).to.match(/https:\/\/localhost:9200\/path\/to\/thing\?(pretty=true|qs=100|&){3}/); + }); + }); + + describe('#write', function () { + var logger; + beforeEach(function () { + logger = makeLogger(); + stub(logger.stream, 'write'); + }); + + it('detects tracer logs by listening messages wrapped in objects', function () { + logger.write('TRACE', { msg: 'msgtext', curl: 'curlcall' }); + expect(logger.stream.write.callCount).to.be(1); + expect(logger.stream.write.lastCall.args[0]).to.contain('msgtext'); + expect(logger.stream.write.lastCall.args[0]).to.contain('curlcall'); + }); + + it('comments everthing except the curl call', function () { + logger.write('TRACE', { msg: 'comment me', curl: 'no comment' }); + expect(logger.stream.write.callCount).to.be(1); + expect(logger.stream.write.lastCall.args[0]).to.match(/^# +comment me/m); + expect(logger.stream.write.lastCall.args[0]).to.match(/^no comment/m); + }); + + it('just comments when it gets a string', function () { + logger.write('TRACE', 'log me'); + expect(logger.stream.write.callCount).to.be(1); + expect(logger.stream.write.lastCall.args[0]).to.match(/^# +log me/m); + }); + }); +}); diff --git a/test/unit/tests/transport.js b/test/unit/specs/transport.js similarity index 98% rename from test/unit/tests/transport.js rename to test/unit/specs/transport.js index a0ecefc7b..c3ec7c3d2 100644 --- a/test/unit/tests/transport.js +++ b/test/unit/specs/transport.js @@ -508,14 +508,15 @@ describe('Transport Class', function () { it('promise is always pulled from the defer created by this.defer()', function () { var fakePromise = {}; var origDefer = Transport.prototype.defer; - Transport.prototype.defer = function () { - return { - resolve: _.noop, - reject: _.noop, - promise: fakePromise - }; - }; - var tran = new Transport({}); + var tran = new Transport({ + defer: function () { + return { + resolve: _.noop, + reject: _.noop, + promise: fakePromise + }; + } + }); shortCircuitRequest(tran); var ret = tran.request({}); Transport.prototype.defer = origDefer; diff --git a/test/unit/tests/transport_with_server.js b/test/unit/specs/transport_with_server.js similarity index 100% rename from test/unit/tests/transport_with_server.js rename to test/unit/specs/transport_with_server.js diff --git a/test/unit/tests/utils.js b/test/unit/specs/utils.js similarity index 100% rename from test/unit/tests/utils.js rename to test/unit/specs/utils.js diff --git a/test/unit/tests/tracer_logger.js b/test/unit/tests/tracer_logger.js deleted file mode 100644 index 832a3fe97..000000000 --- a/test/unit/tests/tracer_logger.js +++ /dev/null @@ -1,43 +0,0 @@ -describe('Tracer Logger', function () { - - var Log = require('../../../src/lib/log'); - var TracerLogger = require('../../../src/lib/loggers/tracer'); - var sinon = require('sinon'); - var expect = require('expect.js'); - var parentLog; - - beforeEach(function () { - parentLog = new Log(); - }); - - afterEach(function () { - parentLog.close(); - }); - - function makeLogger(parent, levels) { - parent = parent || parentLog; - var config = { - levels: Log.parseLevels(levels || 'trace') - }; - return new TracerLogger(parent, config); - } - - var stub = require('../../utils/auto_release_stub').make(); - - - require('../generic_logger_tests')(makeLogger); - - describe('#write', function () { - it('comments out everything accept the curlCall', function () { - var logger = makeLogger(); - - stub(logger.stream, 'write', function (string) { - expect(string.replace(/(^#.*$|^curlcall$)/mg, '').trim()).to.be(''); - }); - - logger.onTrace('message', 'curlcall'); - - expect(logger.stream.write.callCount).to.eql(1); - }); - }); -}); diff --git a/test/utils/server/index.js b/test/utils/server/index.js index ee17da318..e3d06abed 100644 --- a/test/utils/server/index.js +++ b/test/utils/server/index.js @@ -5,30 +5,14 @@ var _ = require('lodash'); var async = require('async'); var path = require('path'); var root = path.join(__dirname, '../../..'); -var glob = require('glob'); var browserify = require('browserify'); var pkg = require(root + '/package.json'); var testFiles = { - unit: 'test/unit/tests/!(' + [ - 'file_logger', - 'http_connector', - 'stdio_logger', - 'console_logger', - 'stream_logger', - 'tracer_logger', - 'transport_with_server', - ].join('|') + ')*.js', - build: 'test/unit/browser_builds/*.js' + unit: 'test/unit/browser.js', + build: 'test/unit/browser_builds/index.js' }; -// resolve the test file globs -_.transform(testFiles, function (out, pattern, name) { - out[name] = _.map(glob.sync(pattern), function (filename) { - return path.resolve(root, filename); - }); -}, testFiles); - // generic aliasify instance var aliasify = require('aliasify').configure({ aliases: pkg.browser,