Openfoodnetwork: When a shopfront's products don't fit into cache, the shop page takes ages to load

[lin-d-hop]

Description

When a shopfront's products don't fit into cache, the shop page takes ages to load. This, at times, can lead to timeouts in which the shopfront just fails to load altogether.

When the list of products for a distributor and OC is not cached the DB is consulted to do that same lookup. This is incredibly slow.

This is done through the /shop/products endpoint.

In particular this is effecting Mercia Food Hub in UK. The shopfront is losing sales. Customers are emailing to say they aren't ordering because the site is failing to load.

Expected Behavior

Shopfronts load successfully without timing out.

Actual Behaviour

Sometimes shopfronts are failing to load.

Steps to Reproduce

1. Identify a shopfront with products missing from the product cache
2. Try to load the shopfront
3. It will take an unacceptable length of time and possibly timeout.

Animated Gif/Screenshot

Insert GIF of an endless OFN spinner here

Context

Shopfronts have reported not being able to load and losing customers as a result.

Severity

Technically this is an S1. However I'm not going to label it as such just yet as we have a plan and it would be nicer to just do the issues than treat it as an S1.

Your Environment

• Version used:
• Browser name and version:
• Operating System and version (desktop or mobile):
• OFN Platform instance where you discovered the bug, and which version of the software they are using.

Possible Fix

To explore this we first need:

• Memcache logging https://github.com/openfoodfoundation/ofn-install/issues/515

[sauloperez]

In particular this is effecting Mercia Food Hub in UK. The shopfront is losing sales. Customers are emailing to say they aren't ordering because the site is failing to load.

would you mind adding a question in Metabase to metric that? even if it's from a dump in staging. I'd really like to validate the value from both business and performance metrics perspective. It's not until then that we can claim we provided value to users.

I can help you on that as I got a bit more familiar now with Metabase.

[lin-d-hop]

@sauloperez I have no idea what you mean in your last comment

[lin-d-hop]

Hi all,
I've upgraded this to an S2.
The user reported 3 people got in touch to say they didn't order from the shop because the shop didn't load in the last order cycle. The actual number effected is unknown.

Although we need a real solution to this, the main priority right now is to have this shops products load into the cache. Any workaround that enables that is fine to remove the S2 label.

Thanks all.

[lin-d-hop]

This is the shop:
https://openfoodnetwork.org.uk/mercia-food-hub/shop

I've tried warming the cache and that hasn't helped.
The user is also willing to remove products from the OC that are offending just to get the shop to load.....

[lin-d-hop]

This is the network times during the request to this shop. 1.3mins waiting for products.

[RachL]

@lin-d-hop is https://github.com/openfoodfoundation/ofn-install/issues/515 already deployed on UK prod?

[Matt-Yorkley]

I don't think it's deployed yet. We can make a branch with that commit plus the new release, and deploy it on Monday.

[sauloperez]

I don't think it's deployed yet. We can make a branch with that commit plus the new release, and deploy it on Monday.

IMO that's a very bad idea. If the release process doesn't fit our needs, adding an exception which we're not familiar with making us deal with yet more complexity won't make things easier thus raising the cost of delivering value to users even more. We've been there already.

Instead, I suggest we move one with whatever comes out of https://community.openfoodnetwork.org/t/release-testing-next-steps/1741

[luisramos0]

1.4minutes to load 481 products..
I tried Tamar Valley Food Hub and it loads 373 products in 1.59seconds.

[luisramos0]

The cache for Mercia is empty. I compared with Tamar for reference:
I think I am looking at the correct OC...

json = Rails.cache.fetch("products-json-160-203569")
ary = JSON.parse(json)
puts ary.count
374

json = Rails.cache.fetch("products-json-201002-203585")
nil

[luisramos0]

I run a refresh cache job for Mercia shop, it runs for a while and ends by returning false, the cache remains empty.

I wonder if this issue is a hypothesis (that the objects dont fit in cache) or a fact (in that case, how do we know this is happening?).

[luisramos0]

I built the cache object in the rails console and it works fine: a json file with the 482 objects.
the command to add the json to the cache returns false and the cache remains empty.
This is definitely something to do with the cache state/config.

[lin-d-hop]

@sauloperez Can you clarify on Luis' comments above. Not sure how you hypothesised this one.

[lin-d-hop]

Ah, sorry, saw the Slack chat now :-) Ignore me...

[luisramos0]

It's really a problem with space in the cache.
I created an array (ary) with the cache elements and then tried to set the cache entry with a smaller set. I can set the cache object with up to 446 objects, but not the total 482 products.

irb(main):085:0> o = Rails.cache.write("products-json-201002-203585", ary[0...446].to_json)
=> 6671238423019257856
irb(main):086:0> o = Rails.cache.write("products-json-201002-203585", ary[0...447].to_json)
=> false

I reopened the OC in question just for a few seconds to test and the shopfront loaded in 630ms with 445 products :+1:

Current status:

• cache fails to be updated if product list is above certain size
• page loads quickly if cache is updated with a partly complete product list

[luisramos0]

ah, one more finding 🎉
it may be the size of the entry, not the overall space available!
It cannot be a coincidence that the size of 446 items (see test above) is just below the 1MByte and the size of 447 is just above 1MB :-D
1 MB = 1048576 bytes

irb(main):089:0> ary[0...446].to_json.bytesize
=> 1045891
irb(main):090:0> ary[0...447].to_json.bytesize
=> 1055973

[luisramos0]

"The default maximum object size is 1MB"
In memcached 1.4.2 and later, you can change the maximum size of an object using the -I command line option.

UK live is on memcached 1.4.25

[lin-d-hop]

What marvellous detective work :-)

[luisramos0]

Moving this to Code Review, the PR increases the max size of memcached objects to 4Mb
https://github.com/openfoodfoundation/ofn-install/pull/531

it's a temporary measure anyway, with paginated results this will not be a problem.

[luisramos0]

this is effectively resolved by 4356, so I am closing it.