feat: Log on successful POST to DCR

[akash1810]

Note

This is a trimmed down version of #28983.

What does this change?

Whilst load testing DCR's tag-page-rendering, we've observed a correlation between payload size and latency. This change adds a log line after a request to DCR has been made to aid debugging. The log line is structured, with markers covering the URL, response code, content length and request duration.

I've attempted to namespace the markers to distinguish them from the request logs.

Whilst RelOps have been load testing DCR running on ECS, we've noticed the latency of a request is sometimes unexpectedly high. Additionally, the size of the payload sent to DCR and the size of DCR's response seem wildly different. We've a hypothesis that payload POSTed to DCR is a superset of what it needs (see also #28964 and #27894).

These logs should help us graph the size of the payload and the time taken to read it, so we can see if there's a correlation between the two.

Warning

This change will create a log line for each DCR request. To reduce noise, we could log only when a request is made to tag-page-rendering as that is the service we (RelOps) are currently looking at.

Example

Take https://www.theguardian.com/tone/minutebyminute, the HTML is 357688 bytes:

❯ curl -I "https://www.theguardian.com/tone/minutebyminute"
HTTP/2 200
content-length: 357688

However, the data POSTed to DCR for this page is 838654 bytes:

❯ curl -I "https://www.theguardian.com/tone/minutebyminute.json?dcr=true"
HTTP/2 200
content-length: 838654

Screenshots

After deploying to CODE, we can see the logs in Central ELK:

Checklist

• Tested locally, and on CODE if necessary
• Will not break dotcom-rendering
• Any new test data/database files generated by tests are committed with this PR (the tests will fail in CI if you've forgotten to do this)
• Meets our accessibility standards
  • Tested with screen reader
  • Navigable with keyboard
  • Colour contrast passed

[github-actions]

Deploy build 7392 of dotcom:frontend-all to CODE

All deployment options

• Deploy build 7392 of dotcom:frontend-all to CODE
• Deploy parts of build 7392 to CODE by previewing it first
• What's on CODE right now?

---

From guardian/actions-riff-raff.

[Jakeii]

Thanks for looking into this!

[gu-prout]

Seen on ADMIN-PROD (merged by @akash1810 8 minutes and 39 seconds ago)

• Check your changes on www.theguardian.com ✔️
• Keep an eye on the deploy dashboard 📉

[gu-prout]

Seen on FRONTS-PROD (merged by @akash1810 9 minutes and 44 seconds ago)

• Check your changes on www.theguardian.com ✔️
• Keep an eye on the deploy dashboard 📉

[akash1810]

This has been running for 2 full days now, producing ~18.5M logs a day:

The Central ELK cluster is still healthy, running with ~55% disk usage: