Add custom serializers to improve app logging #1655
Merged
Conversation
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
We've completed a [number of changes to our logging](https://github.com/DEFRA/water-abstraction-team/issues?q=is%3Aissue%20state%3Aclosed%20log) in the time we have been on the project. Generally, we 'go to the logs' when an issue has been reported in `production` and we need to figure out what has happened. Therefore, we are always balancing ensuring we have all the information we need whilst excluding anything that is just noise. For reasons (😩😬) we've had to deal with a number of live issues in a short space of time recently. Having now dealt with them, we've reflected on what exactly we are currently logging. Our conclusion is that it is still too much! This, for example, is what we are outputting on every `GET` request. ```text 5|system | [15:19:25.232] INFO (1313): [response] get /bill-runs/review/460a2180-34c7-46aa-b72d-dfdb5b6c5472 200 (104ms) 5|system | req: { 5|system | "id": "1737904765128:9bc56d13c48b:1313:m6drmcd1:10001", 5|system | "method": "get", 5|system | "url": "/bill-runs/review/460a2180-34c7-46aa-b72d-dfdb5b6c5472", 5|system | "query": {}, 5|system | "headers": { 5|system | "connection": "keep-alive", 5|system | "cache-control": "max-age=0", 5|system | "upgrade-insecure-requests": "1", 5|system | "user-agent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/132.0.0.0 Safari/537.36", 5|system | "accept": "text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.7", 5|system | "sec-fetch-site": "same-origin", 5|system | "sec-fetch-mode": "navigate", 5|system | "sec-fetch-user": "?1", 5|system | "sec-fetch-dest": "document", 5|system | "sec-ch-ua": "\"Not A(Brand\";v=\"8\", \"Chromium\";v=\"132\", \"Google Chrome\";v=\"132\"", 5|system | "sec-ch-ua-mobile": "?0", 5|system | "sec-ch-ua-platform": "\"macOS\"", 5|system | "referer": "http://localhost:8008/system/bill-runs/review/460a2180-34c7-46aa-b72d-dfdb5b6c5472", 5|system | "accept-encoding": "gzip, deflate, br, zstd", 5|system | "accept-language": "en-GB,en;q=0.9,en-US;q=0.8", 5|system | "cookie": "imagine_a_long_string_made_up_of_a_mish_mash_of_letters_and_numbers_because_it_is_encrypted", 5|system | "x-forwarded-for": "172.18.0.1", 5|system | "x-forwarded-port": "57172", 5|system | "x-forwarded-proto": "http", 5|system | "x-forwarded-host": "localhost:8008", 5|system | "host": "localhost:8013" 5|system | }, 5|system | "remoteAddress": "127.0.0.1", 5|system | "remotePort": 56298 5|system | } 5|system | res: { 5|system | "statusCode": 200, 5|system | "headers": { 5|system | "strict-transport-security": "max-age=15768000", 5|system | "x-frame-options": "DENY", 5|system | "x-xss-protection": "0", 5|system | "x-download-options": "noopen", 5|system | "x-content-type-options": "nosniff", 5|system | "cache-control": "no-cache", 5|system | "set-cookie": [ 5|system | "wrlsSession=Fe26.imagine_a_long_string_made_up_of_a_mish_mash_of_letters_and_numbers_because_it_is_encrypted; Secure; HttpOnly; SameSite=Lax; Path=/" 5|system | ], 5|system | "content-type": "text/html; charset=utf-8", 5|system | "vary": "accept-encoding", 5|system | "content-encoding": "gzip" 5|system | } 5|system | } 5|system | responseTime: 104 ``` However, from our experience of handling issues all we look at is - `req:` - the ID (can be handy to trace transactions), the method, and the URL - `res:` - the status code (did it succeed or error) The rest is pure noise. On the other hand, there is some additional data that could be handy to see, for example, the payload on `POST` requests. This change updates our config for [Hapi-pino](https://github.com/hapijs/hapi-pino) to to tell it to add the following to the logs - the payload - any query params - any path params It also implements our own serializers, which take the one returned by [pino-std-serializers](https://github.com/pinojs/pino-std-serializers) and transform it to only include the properties we care about. With these changes our log output now looks like this. ```text 5|system | [16:33:17.125] INFO (1333): [response] post /bill-runs/review/460a2180-34c7-46aa-b72d-dfdb5b6c5472 302 (58ms) 5|system | req: { 5|system | "id": "1737909197067:9bc56d13c48b:1333:m6du9e83:10000", 5|system | "method": "get", 5|system | "url": "/bill-runs/review/460a2180-34c7-46aa-b72d-dfdb5b6c5472", 5|system | "query": {} 5|system | } 5|system | payload: { 5|system | "filterIssues": "aggregate-factor", 5|system | "filterLicenceStatus": "review" 5|system | } 5|system | queryParams: {} 5|system | pathParams: { 5|system | "billRunId": "460a2180-34c7-46aa-b72d-dfdb5b6c5472" 5|system | } 5|system | res: { 5|system | "statusCode": 302 5|system | } 5|system | responseTime: 58 5|system | [16:33:17.235] INFO (1333): [response] get /bill-runs/review/460a2180-34c7-46aa-b72d-dfdb5b6c5472 200 (99ms) 5|system | req: { 5|system | "id": "1737909197135:9bc56d13c48b:1333:m6du9e83:10001", 5|system | "method": "get", 5|system | "url": "/bill-runs/review/460a2180-34c7-46aa-b72d-dfdb5b6c5472", 5|system | "query": {} 5|system | } 5|system | queryParams: {} 5|system | pathParams: { 5|system | "billRunId": "460a2180-34c7-46aa-b72d-dfdb5b6c5472" 5|system | } 5|system | res: { 5|system | "statusCode": 200 5|system | } 5|system | responseTime: 99 ```
Cruikshanks
added
the
housekeeping
Cruikshanks
requested review from
robertparkinson,
Jozzey,
StuAA78,
jonathangoulding,
Beckyrose200 and
rvsiyad
robertparkinson
approved these changes
Jan 27, 2025
Cruikshanks
added a commit
to DEFRA/water-abstraction-ui
that referenced
this pull request
Jan 27, 2025
We've completed a [number of changes to our logging](https://github.com/DEFRA/water-abstraction-team/issues?q=is%3Aissue%20state%3Aclosed%20log) in the time we have been on the project. Generally, we 'go to the logs' when an issue has been reported in `production`, and we need to figure out what has happened. Therefore, we constantly balance, ensuring we have all the necessary information while excluding noise. We recently [made a change to water-abstraction-system](DEFRA/water-abstraction-system#1655) to reduce the noise in our logs via custom serializers (check it out for more details). This change makes the same change to the logging in this app.
Cruikshanks
added a commit
to DEFRA/water-abstraction-import
that referenced
this pull request
Jan 27, 2025
We've completed a [number of changes to our logging](https://github.com/DEFRA/water-abstraction-team/issues?q=is%3Aissue%20state%3Aclosed%20log) in the time we have been on the project. Generally, we 'go to the logs' when an issue has been reported in `production`, and we need to figure out what has happened. Therefore, we constantly balance, ensuring we have all the necessary information while excluding noise. We recently [made a change to water-abstraction-system](DEFRA/water-abstraction-system#1655) to reduce the noise in our logs via custom serializers (check it out for more details). This change makes the same change to the logging in this app.
Cruikshanks
added a commit
to DEFRA/water-abstraction-permit-repository
that referenced
this pull request
Jan 27, 2025
We've completed a [number of changes to our logging](https://github.com/DEFRA/water-abstraction-team/issues?q=is%3Aissue%20state%3Aclosed%20log) in the time we have been on the project. Generally, we 'go to the logs' when an issue has been reported in `production`, and we need to figure out what has happened. Therefore, we constantly balance, ensuring we have all the necessary information while excluding noise. We recently [made a change to water-abstraction-system](DEFRA/water-abstraction-system#1655) to reduce the noise in our logs via custom serializers (check it out for more details). This change makes the same change to the logging in this app.
Cruikshanks
added a commit
to DEFRA/water-abstraction-returns
that referenced
this pull request
Jan 27, 2025
We've completed a [number of changes to our logging](https://github.com/DEFRA/water-abstraction-team/issues?q=is%3Aissue%20state%3Aclosed%20log) in the time we have been on the project. Generally, we 'go to the logs' when an issue has been reported in `production`, and we need to figure out what has happened. Therefore, we constantly balance, ensuring we have all the necessary information while excluding noise. We recently [made a change to water-abstraction-system](DEFRA/water-abstraction-system#1655) to reduce the noise in our logs via custom serializers (check it out for more details). This change makes the same change to the logging in this app.
Cruikshanks
added a commit
to DEFRA/water-abstraction-tactical-crm
that referenced
this pull request
Jan 27, 2025
We've completed a [number of changes to our logging](https://github.com/DEFRA/water-abstraction-team/issues?q=is%3Aissue%20state%3Aclosed%20log) in the time we have been on the project. Generally, we 'go to the logs' when an issue has been reported in `production`, and we need to figure out what has happened. Therefore, we constantly balance, ensuring we have all the necessary information while excluding noise. We recently [made a change to water-abstraction-system](DEFRA/water-abstraction-system#1655) to reduce the noise in our logs via custom serializers (check it out for more details). This change makes the same change to the logging in this app.
Cruikshanks
added a commit
to DEFRA/water-abstraction-tactical-idm
that referenced
this pull request
Jan 27, 2025
We've completed a [number of changes to our logging](https://github.com/DEFRA/water-abstraction-team/issues?q=is%3Aissue%20state%3Aclosed%20log) in the time we have been on the project. Generally, we 'go to the logs' when an issue has been reported in `production`, and we need to figure out what has happened. Therefore, we constantly balance, ensuring we have all the necessary information while excluding noise. We recently [made a change to water-abstraction-system](DEFRA/water-abstraction-system#1655) to reduce the noise in our logs via custom serializers (check it out for more details). This change makes the same change to the logging in this app.
Cruikshanks
added a commit
to DEFRA/water-abstraction-import
that referenced
this pull request
Jan 27, 2025
We've completed a [number of changes to our logging](https://github.com/DEFRA/water-abstraction-team/issues?q=is%3Aissue%20state%3Aclosed%20log) in the time we have been on the project. Generally, we 'go to the logs' when an issue has been reported in `production`, and we need to figure out what has happened. Therefore, we constantly balance, ensuring we have all the necessary information while excluding noise. We recently [made a change to water-abstraction-system](DEFRA/water-abstraction-system#1655) to reduce the noise in our logs via custom serializers (check it out for more details). This change makes the same change to the logging in this app.
Cruikshanks
added a commit
to DEFRA/water-abstraction-permit-repository
that referenced
this pull request
Jan 27, 2025
We've completed a [number of changes to our logging](https://github.com/DEFRA/water-abstraction-team/issues?q=is%3Aissue%20state%3Aclosed%20log) in the time we have been on the project. Generally, we 'go to the logs' when an issue has been reported in `production`, and we need to figure out what has happened. Therefore, we constantly balance, ensuring we have all the necessary information while excluding noise. We recently [made a change to water-abstraction-system](DEFRA/water-abstraction-system#1655) to reduce the noise in our logs via custom serializers (check it out for more details). This change makes the same change to the logging in this app.
Cruikshanks
added a commit
to DEFRA/water-abstraction-service
that referenced
this pull request
Jan 27, 2025
We've completed a [number of changes to our logging](https://github.com/DEFRA/water-abstraction-team/issues?q=is%3Aissue%20state%3Aclosed%20log) in the time we have been on the project. Generally, we 'go to the logs' when an issue has been reported in `production`, and we need to figure out what has happened. Therefore, we constantly balance, ensuring we have all the necessary information while excluding noise. We recently [made a change to water-abstraction-system](DEFRA/water-abstraction-system#1655) to reduce the noise in our logs via custom serializers (check it out for more details). This change makes the same change to the logging in this app.
Cruikshanks
added a commit
to DEFRA/water-abstraction-returns
that referenced
this pull request
Jan 27, 2025
We've completed a [number of changes to our logging](https://github.com/DEFRA/water-abstraction-team/issues?q=is%3Aissue%20state%3Aclosed%20log) in the time we have been on the project. Generally, we 'go to the logs' when an issue has been reported in `production`, and we need to figure out what has happened. Therefore, we constantly balance, ensuring we have all the necessary information while excluding noise. We recently [made a change to water-abstraction-system](DEFRA/water-abstraction-system#1655) to reduce the noise in our logs via custom serializers (check it out for more details). This change makes the same change to the logging in this app.
Cruikshanks
added a commit
to DEFRA/water-abstraction-tactical-crm
that referenced
this pull request
Jan 27, 2025
We've completed a [number of changes to our logging](https://github.com/DEFRA/water-abstraction-team/issues?q=is%3Aissue%20state%3Aclosed%20log) in the time we have been on the project. Generally, we 'go to the logs' when an issue has been reported in `production`, and we need to figure out what has happened. Therefore, we constantly balance, ensuring we have all the necessary information while excluding noise. We recently [made a change to water-abstraction-system](DEFRA/water-abstraction-system#1655) to reduce the noise in our logs via custom serializers (check it out for more details). This change makes the same change to the logging in this app.
Cruikshanks
added a commit
to DEFRA/water-abstraction-ui
that referenced
this pull request
Jan 27, 2025
We've completed a [number of changes to our logging](https://github.com/DEFRA/water-abstraction-team/issues?q=is%3Aissue%20state%3Aclosed%20log) in the time we have been on the project. Generally, we 'go to the logs' when an issue has been reported in `production`, and we need to figure out what has happened. Therefore, we constantly balance, ensuring we have all the necessary information while excluding noise. We recently [made a change to water-abstraction-system](DEFRA/water-abstraction-system#1655) to reduce the noise in our logs via custom serializers (check it out for more details). This change makes the same change to the logging in this app.
Cruikshanks
added a commit
to DEFRA/water-abstraction-tactical-idm
that referenced
this pull request
Jan 27, 2025
We've completed a [number of changes to our logging](https://github.com/DEFRA/water-abstraction-team/issues?q=is%3Aissue%20state%3Aclosed%20log) in the time we have been on the project. Generally, we 'go to the logs' when an issue has been reported in `production`, and we need to figure out what has happened. Therefore, we constantly balance, ensuring we have all the necessary information while excluding noise. We recently [made a change to water-abstraction-system](DEFRA/water-abstraction-system#1655) to reduce the noise in our logs via custom serializers (check it out for more details). This change makes the same change to the logging in this app.
Cruikshanks
added a commit
to DEFRA/water-abstraction-service
that referenced
this pull request
Jan 27, 2025
We've completed a [number of changes to our logging](https://github.com/DEFRA/water-abstraction-team/issues?q=is%3Aissue%20state%3Aclosed%20log) in the time we have been on the project. Generally, we 'go to the logs' when an issue has been reported in `production`, and we need to figure out what has happened. Therefore, we constantly balance, ensuring we have all the necessary information while excluding noise. We recently [made a change to water-abstraction-system](DEFRA/water-abstraction-system#1655) to reduce the noise in our logs via custom serializers (check it out for more details). This change makes the same change to the logging in this app.
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
We've completed a number of changes to our logging in the time we have been on the project.
Generally, we 'go to the logs' when an issue has been reported in
production, and we need to figure out what has happened.Therefore, we constantly balance, ensuring we have all the necessary information while excluding noise.
For reasons (😩😬), we've had to deal with several live issues in a short space of time recently. Having dealt with them, we've reflected on what we are currently logging.
We conclude that it is still too much!
For example, we are outputting this on every
GETrequest.However, from our experience of handling issues, all we look at is
req:- the ID (can be handy to trace transactions), the method, and the URLres:- the status code (did it succeed or error)The rest is pure noise. On the other hand, additional data would be handy to see, for example, the payload on
POSTrequests.This change updates our config for Hapi-pino to tell it to add the following to the logs
It also implements our own serializers, which take the
reqandresobjects returned by pino-std-serializers and transform them to only include the properties we care about. With these changes, our log output now looks like this.