diff --git a/services/base-json.js b/services/base-json.js index 842b1f2c86..27e48fb01f 100644 --- a/services/base-json.js +++ b/services/base-json.js @@ -6,6 +6,7 @@ const Joi = require('joi') const { checkErrorResponse, asJson } = require('../lib/error-helper') const BaseService = require('./base') const { InvalidResponse } = require('./errors') +const trace = require('./trace') class BaseJsonService extends BaseService { static _validate(json, schema) { @@ -14,7 +15,7 @@ class BaseJsonService extends BaseService { stripUnknown: true, }) if (error) { - this.logTrace( + trace.logTrace( 'validate', emojic.womanShrugging, 'Response did not match schema', @@ -25,13 +26,19 @@ class BaseJsonService extends BaseService { underlyingError: error, }) } else { - this.logTrace('validate', emojic.bathtub, 'JSON after validation', value) + this.logTrace( + 'validate', + emojic.bathtub, + 'JSON after validation', + value, + { deep: true } + ) return value } } async _requestJson({ schema, url, options = {}, errorMessages = {} }) { - const logTrace = (...args) => this.constructor.logTrace('fetch', ...args) + const logTrace = (...args) => trace.logTrace('fetch', ...args) if (!schema || !schema.isJoi) { throw Error('A Joi schema is required') } @@ -48,7 +55,9 @@ class BaseJsonService extends BaseService { .then(checkErrorResponse.asPromise(errorMessages)) .then(asJson) .then(json => { - logTrace(emojic.dart, 'Response JSON (before validation)', json) + logTrace(emojic.dart, 'Response JSON (before validation)', json, { + deep: true, + }) return json }) .then(json => this.constructor._validate(json, schema)) diff --git a/services/base.js b/services/base.js index ce011f4f6f..3d623281f7 100644 --- a/services/base.js +++ b/services/base.js @@ -2,7 +2,6 @@ // See available emoji at http://emoji.muan.co/ const emojic = require('emojic') -const chalk = require('chalk') const { NotFound, InvalidResponse, @@ -16,14 +15,7 @@ const { makeColor, setBadgeColor, } = require('../lib/badge-data') -// Config is loaded globally but it would be better to inject it. To do that, -// there needs to be one instance of the service created at registration time, -// which gets the config injected into it, instead of one instance per request. -// That way most of the current static methods could become instance methods, -// thereby gaining access to the injected config. -const { - services: { trace: enableTraceLogging }, -} = require('../lib/server-config') +const trace = require('./trace') class BaseService { constructor({ sendAndCacheRequest }, { handleInternalErrors }) { @@ -155,20 +147,19 @@ class BaseService { } async invokeHandler(namedParams, queryParams) { - const logTrace = (...args) => this.constructor.logTrace(...args) - logTrace( + trace.logTrace( 'inbound', emojic.womanCook, 'Service class', this.constructor.name ) - logTrace('inbound', emojic.ticket, 'Named params', namedParams) - logTrace('inbound', emojic.crayon, 'Query params', queryParams) + trace.logTrace('inbound', emojic.ticket, 'Named params', namedParams) + trace.logTrace('inbound', emojic.crayon, 'Query params', queryParams) try { return await this.handle(namedParams, queryParams) } catch (error) { if (error instanceof NotFound || error instanceof InvalidParameter) { - logTrace('outbound', emojic.noGoodWoman, 'Handled error', error) + trace.logTrace('outbound', emojic.noGoodWoman, 'Handled error', error) return { message: error.prettyMessage, color: 'red', @@ -177,14 +168,14 @@ class BaseService { error instanceof InvalidResponse || error instanceof Inaccessible ) { - logTrace('outbound', emojic.noGoodWoman, 'Handled error', error) + trace.logTrace('outbound', emojic.noGoodWoman, 'Handled error', error) return { message: error.prettyMessage, color: 'lightgray', } } else if (this._handleInternalErrors) { if ( - !logTrace( + !trace.logTrace( 'unhandledError', emojic.boom, 'Unhandled internal error', @@ -201,7 +192,7 @@ class BaseService { color: 'lightgray', } } else { - logTrace( + trace.logTrace( 'unhandledError', emojic.boom, 'Unhandled internal error', @@ -274,7 +265,7 @@ class BaseService { namedParams, queryParams ) - this.logTrace('outbound', emojic.shield, 'Service data', serviceData) + trace.logTrace('outbound', emojic.shield, 'Service data', serviceData) const badgeData = this._makeBadgeData(queryParams, serviceData) // Assumes the final capture group is the extension @@ -284,31 +275,6 @@ class BaseService { }) ) } - - static _formatLabelForStage(stage, label) { - const colorFn = { - inbound: chalk.black.bgBlue, - fetch: chalk.black.bgYellow, - validate: chalk.black.bgGreen, - unhandledError: chalk.white.bgRed, - outbound: chalk.black.bgBlue, - }[stage] - return colorFn(` ${label} `) - } - - static logTrace(stage, symbol, label, ...content) { - if (enableTraceLogging) { - console.log( - this._formatLabelForStage(stage, label), - symbol, - '\n', - ...content - ) - return true - } else { - return false - } - } } module.exports = BaseService diff --git a/services/base.spec.js b/services/base.spec.js index cdf75850ee..f660c7a7f2 100644 --- a/services/base.spec.js +++ b/services/base.spec.js @@ -3,6 +3,7 @@ const { expect } = require('chai') const { test, given, forCases } = require('sazerac') const sinon = require('sinon') +const trace = require('./trace') const { NotFound, @@ -98,7 +99,7 @@ describe('BaseService', function() { sandbox.restore() }) beforeEach(function() { - sinon.stub(DummyService, 'logTrace') + sandbox.stub(trace, 'logTrace') }) it('Invokes the logger as expected', async function() { const serviceInstance = new DummyService({}, defaultConfig) @@ -108,13 +109,13 @@ describe('BaseService', function() { }, { queryParamA: '!' } ) - expect(DummyService.logTrace).to.be.calledWithMatch( + expect(trace.logTrace).to.be.calledWithMatch( 'inbound', sinon.match.string, 'Service class', 'DummyService' ) - expect(DummyService.logTrace).to.be.calledWith( + expect(trace.logTrace).to.be.calledWith( 'inbound', sinon.match.string, 'Named params', @@ -122,7 +123,7 @@ describe('BaseService', function() { namedParamA: 'bar.bar.bar', } ) - expect(DummyService.logTrace).to.be.calledWith( + expect(trace.logTrace).to.be.calledWith( 'inbound', sinon.match.string, 'Query params', diff --git a/services/service-tester.js b/services/service-tester.js index db591535a1..3f2628d77a 100644 --- a/services/service-tester.js +++ b/services/service-tester.js @@ -1,7 +1,9 @@ 'use strict' const frisby = require('icedfrisby-nock')(require('icedfrisby')) +const emojic = require('emojic') const config = require('../lib/test-config') +const trace = require('./trace') /** * Encapsulate a suite of tests. Create new tests using create() and register @@ -48,6 +50,16 @@ class ServiceTester { .before(() => { this.beforeEach() }) + // eslint-disable-next-line mocha/prefer-arrow-callback + .finally(function() { + // `this` is the IcedFrisby instance. + trace.logTrace( + 'outbound', + emojic.shield, + 'Response', + JSON.parse(this._response.body) + ) + }) this.specs.push(spec) diff --git a/services/trace.js b/services/trace.js new file mode 100644 index 0000000000..0fb30491e6 --- /dev/null +++ b/services/trace.js @@ -0,0 +1,41 @@ +'use strict' + +const chalk = require('chalk') + +// Config is loaded globally but it would be better to inject it. To do that, +// there needs to be one instance of the service created at registration time, +// which gets the config injected into it, instead of one instance per request. +// That way most of the current static methods could become instance methods, +// thereby gaining access to the injected config. +const { + services: { trace: enableTraceLogging }, +} = require('../lib/server-config') + +function _formatLabelForStage(stage, label) { + const colorFn = { + inbound: chalk.black.bgBlue, + fetch: chalk.black.bgYellow, + validate: chalk.black.bgGreen, + unhandledError: chalk.white.bgRed, + outbound: chalk.black.bgBlue, + }[stage] + return colorFn(` ${label} `) +} + +function logTrace(stage, symbol, label, content, { deep = false } = {}) { + if (enableTraceLogging) { + if (deep) { + console.log(_formatLabelForStage(stage, label), symbol) + console.dir(content, { depth: null }) + } else { + console.log(_formatLabelForStage(stage, label), symbol, '\n', content) + } + return true + } else { + return false + } +} + +module.exports = { + logTrace, +}