ETag caching for notes polling - performance analysis
With https://gitlab.com/gitlab-org/gitlab-ce/merge_requests/9036 we introduced ETag caching for notes polling. We deployed it as 9.0 RC 2 around 16.03.2017 04:00 UTC.
Graphs for Projects::NotesController#index.json
- Deployment of RC2 was not recorded in our monitoring dashboard, I marked a rough value with this nice red line
- This endpoint handles notes polling for issues, merge requests, snippets, commits. We introduced ETag caching only for issues. That's why the impact won't be that visible
- A transaction for
Projects::NotesController#index.jsonwill not be recorded if the ETag middleware returns 304 (cache hit) earlier, because it never ends up calling the controller. This is only my assumption about our performance monitoring system /cc @yorickpeterse - We only have 7 days back of data. This means 2 "standard business days" before the deployment and 3 "standard business days" after the deployment.
- Based on this quite limited data the rough estimate is 33% drop in the number of transactions
- Please note that the average number of Redis connections is still 2, it's the maximum number of Redis connections that increased to 4
- I'm confused by the terminology here (a Redis connection vs. a request to Redis). I thought that Redis connections were reused across a single request.
- If we ignore the previous point, this increase is expected. For issues this endpoint will be triggered only for cache misses. For a cache miss we make one Redis request to get the current ETag value and one Redis request to set the new ETag value
Activity
/cc @smcgivern
-
I cannot find any interesting pattern in global Redis stats - https://performance.gitlab.net/dashboard/db/redis-stats?from=1489424233723&to=now. This is good, because it means that the changes didn't have any big negative impact on Redis.
-
Probably related: https://gitlab.com/gitlab-org/gitlab-ce/issues/29582
-
I'll post the analysis of https://performance.gitlab.net/dashboard/db/events tomorrow.
@adamniedzielski Redis Connections here are basically calls to
Redis::Client#connect. This means that during a request we now end up using a maximum of 4 Redis connections. This can happen if Redis is used more often during a request, so it's not necessarily a bad thing.-
Analysis of events from https://performance.gitlab.net/dashboard/db/events
The state from 22-03-2017 14:13 UTC
etag_caching_middleware_used 2046103 etag_caching_cache_hit 1421020 etag_caching_header_missing 258017 etag_caching_key_not_found 271073 etag_caching_resource_changed 95930 - 69.5% of requests resulted in a cache hit.
- 12.6% of requests were a cache miss because they didn't include the header. We can assume that these were the "first requests" so the requests that are fired on a first polling attempt for given issue by given user. We can't do anything to improve the situation here.
- 4.7% of requests were a cache miss because the resource changed. We can't do anything to improve the situation here.
- In 13.2% of cases a request had the header set, but the given key could not be found in Redis. This means that the cache expired. It is something that we can try to improve by increasing the cache expiration time.
If 69.5% of requests were cache hits, and we didn't change the polling frequency, then why do we only see a '33% drop in the number of transactions'?
One thing that I noticed is totally missing from here, but probably doesn't matter too much - we don't know how fast the cached requests are. However, the important thing is that we are hitting the DB much less often when things don't change. @adamniedzielski wdyt about making the expiration time, along with the polling interval, configurable?
-
@smcgivern I think that the experiment is quite successful. Still, 30% of requests go through our regular processing that involves more expensive SQL queries. I don't expect that we will be able to make this number lower than 25% (for issue notes polling) by increasing the expiry time (but we can try to get these 5 percentage points).
If we decrease the polling interval then I expect the percentage of cache hits to be higher (more requests in total, the same number of "first requests", the same number of resource changes).
If 69.5% of requests were cache hits, and we didn't change the polling frequency, then why do we only see a '33% drop in the number of transactions'?
because:
This endpoint handles notes polling for issues, merge requests, snippets, commits. We introduced ETag caching only for issues.
It took me a few days to notice it
wdyt about making the expiration time [...] configurable?
I'd rather increase it to 20 minutes (from 10 minutes) and leave as a constant. If it's difficult for us to find an optimal value then for users that are not GitLab.com this configuration option would be basically meaningless.
-
@smcgivern Should I open issues for using ETag caching for notes polling on other resources? Some of them may be tricky (merge request), but others should be easier.
@adamniedzielski please do! For the expiration time bump, feel free to either open a separate issue, or just open an MR if that's quicker.
@adamniedzielski amazing work on this analysis. Really interesting to read through, and really well done. And on the implementation too.
Looking forward to seeing if the cache hit ratio can be further improved with longer caching times.
mentioned in commit e946bbe1
mentioned in merge request !10180 (merged)
mentioned in issue #29939 (moved)
mentioned in issue #29940 (moved)
mentioned in issue #29941 (moved)
-
Follow-up issues:
- https://gitlab.com/gitlab-org/gitlab-ce/issues/29939
- https://gitlab.com/gitlab-org/gitlab-ce/issues/29940
- https://gitlab.com/gitlab-org/gitlab-ce/issues/29941
(managed to get uninterrupted IDs, ha!)
mentioned in issue #29582 (closed)
mentioned in merge request !10280 (merged)
