Skip to content

Commit

Permalink
Only log essential info on failed requests (#139)
Browse files Browse the repository at this point in the history 
https://eaflood.atlassian.net/browse/WATER-3906

When working on the [Spike - Create a complete debit only SROC bill run](#133) a request to the [sroc-charging-module-api](https://github.com/DEFRA/sroc-charging-module-api) failed, as in we got a `4xx/5xx` response.

One of the things that made it hard to track down the cause as we are currently dumping the full response object [Got](https://github.com/sindresorhus/got) returns into the log.

Should **Got** throw an exception, for example, when a network error occurs we'll want to see everything. But if the request fails because the Charging Module has returned an error response, we just want to see that information.

So, this tweaks the logging in `RequestLib` to ensure this.

---

We also took advantage of making these changes to do some boy scout cleanup and remove the duplication across the `get()` and `post()` methods.

Co-authored-by: Jason Claxton <30830544+Jozzey@users.noreply.github.com>
  • Loading branch information
@Cruikshanks @Jozzey
Cruikshanks and Jozzey authored Mar 3, 2023
1 parent a1e22b0 commit 38e2e37
Show file tree
Hide file tree
Showing 2 changed files with 84 additions and 41 deletions.
67 changes: 38 additions & 29 deletions app/lib/request.lib.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -27,36 +27,18 @@ const requestConfig = require('../../config/request.config.js')
*
* @param {string} url The full URL that you wish to connect to
* @param {Object} additionalOptions Append to or replace the options passed to Got when making the request
*
* @returns {Object} The result of the request; whether it succeeded and the response or error returned
*/
async function get (url, additionalOptions = {}) {
const got = await _importGot()
const result = {
succeeded: false,
response: null
}

try {
const options = _requestOptions(additionalOptions)

result.response = await got.get(url, options)

// If the result is not 2xx or 3xx Got will mark the result as unsuccessful using the response object's `ok:`
// property
result.succeeded = result.response.ok
} catch (error) {
// If it's a network error, for example 'ETIMEDOUT', we'll end up here
result.response = error
}

if (!result.succeeded) {
_logFailure('GET', result, url, additionalOptions)
}

return result
return await _sendRequest('get', url, additionalOptions)
}

async function post (url, additionalOptions = {}) {
return await _sendRequest('post', url, additionalOptions)
}

async function _sendRequest (method, url, additionalOptions) {
const got = await _importGot()
const result = {
succeeded: false,
Expand All @@ -66,7 +48,7 @@ async function post (url, additionalOptions = {}) {
try {
const options = _requestOptions(additionalOptions)

result.response = await got.post(url, options)
result.response = await got[method](url, options)

// If the result is not 2xx or 3xx Got will mark the result as unsuccessful using the response object's `ok:`
// property
Expand All @@ -77,7 +59,7 @@ async function post (url, additionalOptions = {}) {
}

if (!result.succeeded) {
_logFailure('POST', result, url, additionalOptions)
_logFailure(method.toUpperCase(), result, url, additionalOptions)
}

return result
Expand All @@ -93,17 +75,44 @@ async function _importGot () {
return got
}

/**
* Logs the failed request
*
* If the request failed because the external service returned a `4xx/5xx` response we just log the failure. We also
* generate our own response object to avoid outputting the full response object Got generates.
*
* If the request failed because of an error, for example a timeout, then we both log and send a notification to our
* Errbit instance. We also output the full response to the log as it will be the Got error containing all the info
* we need to diagnose the problem.
*
* @param {string} method the type of request made, for example, 'GET', 'POST, or 'PATCH'
* @param {Object} result the result object we generate
* @param {*} url the requested url
* @param {*} additionalOptions any additional options that were passed to Got by the calling service
*/
function _logFailure (method, result, url, additionalOptions) {
const data = {
method,
result,
url,
additionalOptions
}

const severity = result.response instanceof Error ? 'errored' : 'failed'
if (result.response instanceof Error) {
data.result = result
global.GlobalNotifier.omfg(`${method} request errored`, data)

return
}

data.result = {
succeeded: result.succeeded,
response: {
statusCode: result.response.statusCode,
body: result.response.body
}
}

global.GlobalNotifier.omfg(`${method} request ${severity}`, data)
global.GlobalNotifier.omg(`${method} request failed`, data)
}

/**
Expand Down
58 changes: 46 additions & 12 deletions test/lib/request.lib.test.js
View file
Original file line number Diff line number Diff line change
Expand Up @@ -23,7 +23,7 @@ describe('RequestLib', () => {
// RequestLib depends on the GlobalNotifier to have been set. This happens in app/plugins/global-notifier.plugin.js
// when the app starts up and the plugin is registered. As we're not creating an instance of Hapi server in this
// test we recreate the condition by setting it directly with our own stub
notifierStub = { omfg: Sinon.stub() }
notifierStub = { omg: Sinon.stub(), omfg: Sinon.stub() }
global.GlobalNotifier = notifierStub
})

Expand Down Expand Up @@ -62,10 +62,20 @@ describe('RequestLib', () => {
Nock(testDomain).get('/').reply(500, { data: 'hello world' })
})

it('records the failure', async () => {
it('logs the failure', async () => {
await RequestLib.get(testDomain)

expect(notifierStub.omfg.calledWith('GET request failed')).to.be.true()
const logDataArg = notifierStub.omg.args[0][1]

expect(notifierStub.omg.calledWith('GET request failed')).to.be.true()
expect(logDataArg.method).to.equal('GET')
expect(logDataArg.url).to.equal('http://example.com')
expect(logDataArg.additionalOptions).to.equal({})
expect(logDataArg.result.succeeded).to.be.false()
expect(logDataArg.result.response).to.equal({
statusCode: 500,
body: '{"data":"hello world"}'
})
})

describe('the result it returns', () => {
Expand All @@ -75,7 +85,7 @@ describe('RequestLib', () => {
expect(result.succeeded).to.be.false()
})

it("has a 'response' property containg the web response", async () => {
it("has a 'response' property containing the web response", async () => {
const result = await RequestLib.get(testDomain)

expect(result.response).to.exist()
Expand All @@ -90,10 +100,17 @@ describe('RequestLib', () => {
Nock(testDomain).get('/').replyWithError({ code: 'ECONNRESET' })
})

it('records the error', async () => {
it('logs and records the error', async () => {
await RequestLib.get(testDomain)

const logDataArg = notifierStub.omfg.args[0][1]

expect(notifierStub.omfg.calledWith('GET request errored')).to.be.true()
expect(logDataArg.method).to.equal('GET')
expect(logDataArg.url).to.equal('http://example.com')
expect(logDataArg.additionalOptions).to.equal({})
expect(logDataArg.result.succeeded).to.be.false()
expect(logDataArg.result.response).to.be.an.error()
})

describe('the result it returns', () => {
Expand All @@ -103,7 +120,7 @@ describe('RequestLib', () => {
expect(result.succeeded).to.be.false()
})

it("has a 'response' property containg the error", async () => {
it("has a 'response' property containing the error", async () => {
const result = await RequestLib.get(testDomain)

expect(result.response).to.exist()
Expand Down Expand Up @@ -137,7 +154,7 @@ describe('RequestLib', () => {
expect(result.succeeded).to.be.false()
})

it("has a 'response' property containg the error", async () => {
it("has a 'response' property containing the error", async () => {
const result = await RequestLib.get(testDomain)

expect(result.response).to.exist()
Expand Down Expand Up @@ -165,7 +182,7 @@ describe('RequestLib', () => {
expect(result.succeeded).to.be.true()
})

it("has a 'response' property containg the web response", async () => {
it("has a 'response' property containing the web response", async () => {
const result = await RequestLib.get(testDomain)

expect(result.response).to.exist()
Expand All @@ -185,7 +202,7 @@ describe('RequestLib', () => {

it('adds them to the options used when making the request', async () => {
// We tell Got to return the response as json rather than text. We can confirm the option has been applied by
// checking the result.reponse.body below.
// checking the result.response.body below.
const options = { responseType: 'json' }
const result = await RequestLib.get(testDomain, options)

Expand Down Expand Up @@ -240,10 +257,20 @@ describe('RequestLib', () => {
Nock(testDomain).post('/').reply(500, { data: 'hello world' })
})

it('records the failure', async () => {
it('logs the failure', async () => {
await RequestLib.post(testDomain)

expect(notifierStub.omfg.calledWith('POST request failed')).to.be.true()
const logDataArg = notifierStub.omg.args[0][1]

expect(notifierStub.omg.calledWith('POST request failed')).to.be.true()
expect(logDataArg.method).to.equal('POST')
expect(logDataArg.url).to.equal('http://example.com')
expect(logDataArg.additionalOptions).to.equal({})
expect(logDataArg.result.succeeded).to.be.false()
expect(logDataArg.result.response).to.equal({
statusCode: 500,
body: '{"data":"hello world"}'
})
})

describe('the result it returns', () => {
Expand All @@ -268,10 +295,17 @@ describe('RequestLib', () => {
Nock(testDomain).post('/').replyWithError({ code: 'ECONNRESET' })
})

it('records the error', async () => {
it('logs and records the error', async () => {
await RequestLib.post(testDomain)

const logDataArg = notifierStub.omfg.args[0][1]

expect(notifierStub.omfg.calledWith('POST request errored')).to.be.true()
expect(logDataArg.method).to.equal('POST')
expect(logDataArg.url).to.equal('http://example.com')
expect(logDataArg.additionalOptions).to.equal({})
expect(logDataArg.result.succeeded).to.be.false()
expect(logDataArg.result.response).to.be.an.error()
})

describe('the result it returns', () => {
Expand Down

0 comments on commit 38e2e37

Please sign in to comment.