Reduce CPU & network consumption of Facia JSON download

[rtyley]

This PR looks to fix #26335 by improving the scalability of Facia's pressed-page-json loading code in FrontJsonFapi. Originally it focussed only on adopting AWS SDK v2 to allow non-blocking async code for the downloading, but it now additionally includes a more significant change: ETag-based caching.

ETag caching is a pretty wonderful standard part of the HTTP protocol, relying on these 3 components:

• ETag HTTP response header - a hash of the content, returned by the server
• If-None-Match HTTP request header - sent by the client, to indicate what content it already has, by sending its ETag
• 304 Not Modified HTTP response code - returned by a server when content is unchanged from the supplied ETag, with an otherwise blank response (no need to return a response!)

I've extracted the code needed for an ETagCache into a new library at https://github.com/guardian/etag-caching .

ETag Caching Benefits

• Significant savings in terms of resources:
  • Network: PressedPages are only re-downloaded if the S3 content has changed
  • CPU: Cached PressedPages are only re-parsed if the S3 content has changed
• Retains the 'stay current' behaviour of the old, non-caching solution: S3 queried with every request to ensure the ETag is up-to-date.
• Also, given the cache is based on the (S)Caffeine caching library:
  • In-flight requests for a given key are unified, so 100 simultaneous requests for a key make just 1 fetch-and-parse

The fetching and parsing code is also improved:

• Updated to AWS SDK v2, using non-blocking async code to avoid blocking threads while downloading the Facia JSON data from S3
• Directly transform bytes into JsValue, without constructing a String first

Memory requirements of caching

Currently facia runs on c6g.2xlarge instances (16GB RAM), with a JVM heap of 12GB. I'm going to suggest that it's reasonable for the ETagCache to consume up to 4GB of the 12GB RAM.

There are ~300 fronts, each of which can have 4 different variants, so currently there could be up to 1200 different PressedPage objects. From heapdump analysis, the largest PressedPage retains ~22MB of memory (most instances are smaller, averaging at 4MB). With the 4GB budget, and assuming a worse case of 22MB per PressedPage, we can afford to set a max size on the cache of ~180 entries. Although it's disappointing we can't hold all of the PressedPages, the priorities of the eviction policy used by the Caffeine caching library should ensure that we get a good hit rate on the most in-demand fronts.

Incidentally, heapdump analysis also shows that some structures within PressedPage are memory inefficient when considered from the perspective of holding many PressedPage objects in memory at once - using object pooling on model.Tag for instance, would probably lead to a 80% reduction of the total retained memory.

Removal of FutureSemaphore

FutureSemaphore, introduced in November 2017 with #18331, is removed in this change - as described in #26335 (comment) & #26336 (comment), the late-stage 32-concurrent-decoding-processes limit was harmful: it led to work (JSON download & String generation) being thrown away, without the result of that work being cached by the CDN.

Testing

Testing total request-response time on CODE:

$ ssm cmd -p frontend -t facia,frontend,code -c "curl -sS --head -w ',result,%{url_effective},%{time_total}\n' http://localhost:9000/uk | grep -e result -e Commit | tr -d '\r\n'" 2> /dev/null | grep Commit | cut -d' ' -f2 | cut -d',' -f1,3- | sort
34d8b3ac2752dc35bae52240c82ebd48945a3408,http://localhost:9000/uk,0.883647
34d8b3ac2752dc35bae52240c82ebd48945a3408,http://localhost:9000/uk,0.986826
34d8b3ac2752dc35bae52240c82ebd48945a3408,http://localhost:9000/uk,1.013991
34d8b3ac2752dc35bae52240c82ebd48945a3408,http://localhost:9000/uk,1.022075
eb1fdaeb1db72479be8b51e06351f905b72d479b,http://localhost:9000/uk,0.626043
eb1fdaeb1db72479be8b51e06351f905b72d479b,http://localhost:9000/uk,0.629217
eb1fdaeb1db72479be8b51e06351f905b72d479b,http://localhost:9000/uk,0.645948
eb1fdaeb1db72479be8b51e06351f905b72d479b,http://localhost:9000/uk,0.669940

[rtyley]

I've talked this through with @abeddow91, @arelra, @ioannakok, @georgeblahblah and @ParisaTork at the 2pm meeting today, and response was positive, no blocking objections!

Some evidence shared:

• During the meeting: with the CODE Facia ASG 50/50 split between 4 old instances on the main branch with 34d8b3a, and 4 new ones on eb1fdae, the new code demonstrated consistently faster response times on single requests to the /uk front:

$ ssm cmd -p frontend -t facia,frontend,code -c "curl -sS --head -w ',result,%{url_effective},%{time_total}\n' http://localhost:9000/uk | grep -e result -e Commit | tr -d '\r\n'" 2> /dev/null | grep Commit | cut -d' ' -f2 | cut -d',' -f1,3- | sort
34d8b3ac2752dc35bae52240c82ebd48945a3408,http://localhost:9000/uk,0.883647
34d8b3ac2752dc35bae52240c82ebd48945a3408,http://localhost:9000/uk,0.986826
34d8b3ac2752dc35bae52240c82ebd48945a3408,http://localhost:9000/uk,1.013991
34d8b3ac2752dc35bae52240c82ebd48945a3408,http://localhost:9000/uk,1.022075
eb1fdaeb1db72479be8b51e06351f905b72d479b,http://localhost:9000/uk,0.626043
eb1fdaeb1db72479be8b51e06351f905b72d479b,http://localhost:9000/uk,0.629217
eb1fdaeb1db72479be8b51e06351f905b72d479b,http://localhost:9000/uk,0.645948
eb1fdaeb1db72479be8b51e06351f905b72d479b,http://localhost:9000/uk,0.669940

• Captured prior to the meeting: Two snapshots of heap memory usage on a local instance of Frontend/DCR while testing with 50 concurrent requests to the /uk front:
  • Old code on main: heap rises quickly to 8GB/12GB, significant GC activity
    
  • This PR: heap never goes higher than 1.5GB, GC activity is not visible
    

[bryophyta]

There are ~300 fronts, each of which can have 4 different variants, so currently there could be up to 1200 different PressedPage objects

Thanks for the detailed write-up @rtyley! Not sure if this has come up already, but (iirc) the only reason @ioannakok and I were able to find for having a lite version, when we looked into it, was to save some parsing overhead. I haven't followed this PR in detail, but if the new caching strategy tips the balance significantly in favour of having fewer page objects in memory then that might offset the overhead from having to parse the 'full' version of the page json when it is parsed.

Might be worth looking into if it hasn't been discussed yet?

[rtyley]

@ioannakok and I were able to find for having a lite version, when we looked into it, was to save some parsing overhead.

Ah interesting - that would have been #18364 & #18365 ...

I haven't followed this PR in detail, but if the new caching strategy tips the balance significantly in favour of having fewer page objects in memory then that might offset the overhead from having to parse the 'full' version of the page json when it is parsed.

That is a super interesting point @bryophyta ! Looking at the uncompressed files sizes for s3://aws-frontend-store/PROD/frontsapi/pressed/live/uk/fapi/:

5980936 pressed.v2.adfree.json
4025640 pressed.v2.lite.adfree.json

6063014 pressed.v2.json
4107718 pressed.v2.lite.json

...the lite versions aren't even dramatically smaller - they are still 67% of the same size as the original versions of those files.

So I think you're right - they're adding 67% to storage requirements (assuming that the Scala case-class memory representation is roughly proportional to the file size) and are actively harmful to the cache hit rate, now that we're using a cache.

Subsequent to this PR, in a new PR, I definitely agree: the 'lite' versions should be completely removed. The only thing to watch out for would be to see if the output of the endpoints that use the 'lite' versions (renderFrontHeadline()
renderFrontPressResult() & renderFrontJsonMinimal()) stays the same, depending whether they perform their own trimming that will work on the full versions of PressedPage, or if were relying on the trimmed nature of the 'lite' version at all. I've created #27143 to track this.

[bryophyta]

Thanks for this!

The only thing to watch out for would be to see if the output of the endpoints that use the 'lite' versions (renderFrontHeadline() renderFrontPressResult() & renderFrontJsonMinimal()) stays the same, depending whether they perform their own trimming that will work on the full versions of PressedPage, or if were relying on the trimmed nature of the 'lite' version at all.

Agreed that we'd need to check implications for consumers 👍 Hopefully it should be easy enough to repurpose the existing code that creates the lite versions in the current implementation, and run it when those endpoints are hit?

From what I remember though it might take a little bit of detective work to find out who the consumers are though (I happen to know that one of the consumers of renderFrontJsonMinimal() is the Pressreader lambdas, but that's only because by coincidence I've been working on those on my new team.)

But ultimately up to WebX to decide whether it's something to prioritise of course 🙂

[ioannakok]

Since we're deleting BlockingOperations this config can also be removed.

[rtyley]

Ah, that bit of config is still used by the BlockingOperations class, and that hasn't been deleted (unfortunately?!) - we're no longer using it for the Fronts-JSON download code, but it's still used elsewhere, eg dfp.OrderAgent.

[ioannakok]

Fantastic work @rtyley 👏 Thank you for doing this and for the great PR write-up!

[mchv]

Excellent work @rtyley 💎

[rtyley]

Thanks all! I'm looking to merge this today, and deploy it to PROD - I would like to pair with a WebX person on the release? Would be good to keep an eye on the graphs as it goes out.

Some useful graphs:

• ELK
• front-download-latency & front-decoding-latency

[sophie-macmillan]

After deploying, current state of play is:

Average latency & front not modified download latency

Network In and CPU utalization

Used heap & garbage collection

[sophie-macmillan]

We've reduced the number of instances at 3.20pm (real time, 2.20 in aws), and are monitoring the impact on the metrics

CPU utilisation was stable after the deploy at 12.20 (real time, 11.20 in aws), we're seeing a slight increase after reducing instances but this is to be expected

Average latency has jumped slightly, but this metric includes the metrics for front-not-modified-download-latency

Used heap memory dropped significantly after the deploy, but has jumped back up after we reduced the number of instances (as expected). Garbage collection has also increased, likely due to things being dropped out of the cache.

[rtyley]

So far, I would say this looks healthy overall (and we're back to running with 3 EC2 instances!), tho' two metrics are perturbing, need follow up.

Good news

Average CPU utilisation in the EC2 ASG dropped when we deployed this PR - and rose when we halved the number of instances from 6 to 3 - but it did not quite double 👍 (graph):

More than half of S3 requests are now receiving NOT MODIFIED - and this proportion even raised slightly as we halved the number of instances from 6 to 3 (graph):

Decoding the bytes to PressedPages is now slightly faster - that, I can't quite explain! (graph):

Concerning metrics

Download time

Despite more than half of them being empty NOT MODIFIED responses, the overall average download time has risen (graph):

I can't easily explain this - I feel like either AWS SDK v2 is actually somehow slower than v1, or possibly the fact that we're using async and need to wait for a thread to process the result of the response?!

Garbage collection

Garbage collections have increased (graph) - this is kind of what you'd expect when you hold more objects in memory, but still not very nice to see. I think the main problem here is that the cache max size (180) is pretty small, and so this leads to quite a lot of cache thrashing- if we could hold more PressedPages in memory, we would see less garbage collection.

I feel like a lot of this bad stuff can be addressed by reducing the memory footprint of a PressedPage -something for a subsequent PR.

[prout-bot]

Seen on FRONTS-PROD, ADMIN-PROD (created by @rtyley and merged by @sophie-macmillan 8 hours, 59 minutes and 39 seconds ago)

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