Optimise shops page: Enable injected enterprise data to be scoped to specific enterprise ids

[johansenja]

What? Why?

When visiting https://openfoodnetwork.org.uk/shops, the page load is very slow. Given that this page is linked to from the
CTA above the fold on https://openfoodnetwork.org.uk/, it seems ideal that should load quickly.

It appears that part of the problem is that the InjectionHelper (via OpenFoodNetwork::EnterpriseInjectionData) fetches information about all enterprises (even ones which don't need to be serialised).

In some cases there could be a lot of rows pulled from the DB into memory, especially in the cases where there are joins (eg. Spree::Taxon.supplied_taxons pulls in all taxons of all products for all enterprises) - and then sometimes there are application-side operations happening on them too (eg. looping or creating hashes).

I opted to make this scoping optional where possible to try to ensure that they are non-breaking for other areas

I did a bit of benchmarking locally using

ab -n 20 -c 1 -H 'Accept: text/html'  -H 'Cookie: ...' 'http://localhost:3000/shops#/'

for this branch against master, and these were the results:

master (1940ms page load average):

This is ApacheBench, Version 2.3 <$Revision: 1903618 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/

Benchmarking localhost (be patient).....done


Server Software:        
Server Hostname:        localhost
Server Port:            3000

Document Path:          /shops#/
Document Length:        44150 bytes

Concurrency Level:      1
Time taken for tests:   38.817 seconds
Complete requests:      20
Failed requests:        19
   (Connect: 0, Receive: 0, Length: 19, Exceptions: 0)
Total transferred:      922991 bytes
HTML transferred:       884035 bytes
Requests per second:    0.52 [#/sec] (mean)
Time per request:       1940.863 [ms] (mean)
Time per request:       1940.863 [ms] (mean, across all concurrent requests)
Transfer rate:          23.22 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.0      0       0
Processing:  1697 1941 218.5   1815    2531
Waiting:     1696 1941 218.5   1815    2531
Total:       1697 1941 218.5   1815    2532

Percentage of the requests served within a certain time (ms)
  50%   1815
  66%   2015
  75%   2095
  80%   2132
  90%   2259
  95%   2532
  98%   2532
  99%   2532
 100%   2532 (longest request)

this branch (686ms page load average):

This is ApacheBench, Version 2.3 <$Revision: 1903618 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/

Benchmarking localhost (be patient).....done


Server Software:        
Server Hostname:        localhost
Server Port:            3000

Document Path:          /shops#/
Document Length:        43823 bytes

Concurrency Level:      1
Time taken for tests:   13.730 seconds
Complete requests:      20
Failed requests:        19
   (Connect: 0, Receive: 0, Length: 19, Exceptions: 0)
Total transferred:      914886 bytes
HTML transferred:       879896 bytes
Requests per second:    1.46 [#/sec] (mean)
Time per request:       686.478 [ms] (mean)
Time per request:       686.478 [ms] (mean, across all concurrent requests)
Transfer rate:          65.07 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.2      0       1
Processing:   543  686  91.4    671     955
Waiting:      543  686  91.4    670     955
Total:        543  686  91.4    671     956

Percentage of the requests served within a certain time (ms)
  50%    671
  66%    684
  75%    745
  80%    757
  90%    814
  95%    956
  98%    956
  99%    956
 100%    956 (longest request)

What should we test?

• The /shops page is the main one
• The groups page (eg /groups/1#/map) - from inject_group_enterprises
• The order show or edit page (eg /orders/R888114387) - from inject_enterprise_and_relatives

The other 2 pages incidentally also seem to be quicker for me, by a similar amount

Release notes

Changelog Category (reviewers may add a label for the release notes):

• Technical changes only

Dependencies

Documentation updates

[johansenja]

These are a lot of whitespace changes in this file (changed from module Spree nesting to RSpec.describe Spree::Taxon to avoid linting problems) - I would recommend hiding whitespace to view, to distinguish the functional differences

[rioug]

That's awesome ! thanks @johansenja
Keep them coming 😄

[dacook]

I've often noticed how slow it was and thought "surely we can improve this..". So thanks for taking on this big task to improve the performance!

Firstly, I have a few general notes:

• When adding specs to cover existing code, it's best to add them in an earlier commit (you can re-arrange commits with git). Then, when you add your changes we can more clearly see what behaviour was existing, and what features you've added.
• It's worth running the linter each time you commit, so that you can catch these adjustments earlier, and keep the git history simple

I also have a suggestion, for bonus points:
We have an rspec matcher to check what DB queries are running. This seems like a great opportunity to test that it's running only the necessary queries. See here for examples, or a real example here
This could be added in a separate PR though; I think it's worth proceeding with manual testing.

[dacook]

I looked up the hash method to make sure I understood it, and discovered that it only creates a reproducible hash within the current process (ref https://stackoverflow.com/questions/2505824/how-does-rubys-string-hash-method-work)
For example:

~/projects/openfoodnetwork $ ruby -e "puts [1,2,3].hash"
1856927473914424695
~/projects/openfoodnetwork $ ruby -e "puts [1,2,3].hash"
3622279804335312461

As far as I can tell, we have shared cache between server processes (with redis_cache_store), so the benefit of caching will be reduced. It means we'll end up with perhaps 4 times the cache entries (assuming 4 puma processes which don't often crash and restart).

Hmm it should be fine :)
It's probably more performant than generating a more persistent hash.

[johansenja]

Ah, that's a good point. My hope here would be that caching wouldn't even be needed if fetching and processing the data is fast enough - currently, CacheService.cached_data_by_class performs an extra DB query just to generate the cache key cached_class.maximum(:updated_at).to_f; on my machine it normally takes a few ms but has taken up to 45ms (though maybe it would be more consistent with an index on updated_at), but it's a similar time to actually pulling all the rows anyway:

Though I'm sure production data would be a bit different!

As far as I can tell, this is the only code that uses CacheService.cached_data_by_class, so there could be an opportunity to simplify the CacheService if the EnterpriseInjectionData no longer needed it

[dacook]

Ah, I see. It seems pointless making an extra DB query to find out if we need to make the real query, when we could just make the real query. Perhaps with further optimisation, the real query might be quite efficient (I just added a comment to Spree::Taxon.supplied_taxons)

[johansenja]

Thanks for the review. It's useful to know about the rspec matchers, because I have a few other changes in mind which could benefit from them. With these changes, I don't think I'll be chaning the number of queries, though there are a few areas which might (see #12724 - there are definitely some n+2s in there but I think I have a better solution for it)

[dacook]

Ah, I see. It seems pointless making an extra DB query to find out if we need to make the real query, when we could just make the real query. Perhaps with further optimisation, the real query might be quite efficient (I just added a comment to Spree::Taxon.supplied_taxons)

[dacook]

Great, thank you!

[dacook]

Just needs a conflict fix, then we can do a manual test.

[drummer83]

Hi @johansenja,
There's a conflict here. Could you please have a look?
I will try to test as soon as possible then.
Thanks!

[johansenja]

Yup no problem, I have just rebased against master and pushed again. Many thanks!

[johansenja]

I am not sure about the new test failure now - I was wondering if it could be a flake, but it seems suspcious that it is in the order cycles area, though I'm not yet sure how my changes here would affect it. I'll take another look in due course

[drummer83]

Ja, I guess they are flaky. It's all green now.

[drummer83]

Hi @johansenja,
Thank you so much for working on the performance! It's so important, but often neglected unfortunately.
I staged your PR to our staging server and couldn't spot any issues. It's hard to tell if there is a significant improvement on the page loading time. I don't have the skills to use any tools for that.
However, I didn't find any problems, so this PR is ready to being merged.

For now I will move it to Ready To Go, to double check if we need another approval after you fixed the conflict.
@openfoodfoundation/core-devs Could you please check if another approval is required? Otherwise please go ahead and merge.

Thanks again! 🥳

[mkllnk]

To test performance, roughly, I logged into uk-staging and did a few requests:

time for i in `seq 10`; do curl 'https://staging.openfoodnetwork.org.uk/shops#/' > /dev/null; done

The results are between 2.5s and 3.0s for ten requests but most of the time 2.9s. That's on another pull request.

After staging this pull request, the ten requests finish in 2.5s to 2.7s. That's an improvement.