Kong: Strange behaviour of cache after error: Failed to get from node cache: could not write to lua_shared_dict: no memory error

[RobertMlo]

Summary

When I set LRU_SIZE and MEM_CACHE_SIZE like in _Steps To Reproduce_ chapter, I receive a following log in second attempt to cache a file that size is 100 MB:

failed to get from node cache: could not write to lua_shared_dict: no memory

I expected this error as I set 128 MB for a memory cache size, but I also expected to get this error for every next time until a TTL for first cached file expired. Instead of that, when I cache next several files after got error, I don't receive the error any more and a cache mechanism is still working. It is still working, but there are two things that I noticed:
1) When I inkove a _cache:probe(key)_ function for every keys, I don't receive the TTL values for them as well as an error (there are nils for TTL and error), except for the last one.
2) If I a _cache:get(key, ...)_ function for every keys, I receive my cached values (they are from L1/L2), except for the key for which I received the _no memory_ error (in this case the value is fetching from L3). I also verified a checksum these cached files - they are the same with the original one.

What was there happen? How does it work?

Note that if we create files where each file has 200 MB (MEM_CACHE_SIZE = 128m), then we receive _no memory_ error for every time when we invoke the _cache:get()_ function as it should work.

Note that even if I clear the Kong cache by menas of a _cache:purge()_ function after the error, it still doesn't show me _no memory_ error any more after cached several files.

Steps To Reproduce

1. Create an API and add a custom plugin to it in which you will handle the case below.
2. Set LRU_SIZE = 10 in a cache.lua file.
3. Set MEM_CACHE_SIZE = 128m in a nginx_kong.lua config file.
4. Create 10 files with different content. Each file should have 100 MB.
5. Cache these files under different keys using the _cache:get()_ function.
6. Invoke the _cache:probe()_ function for every keys (begin from first that was added to the cache).
7. Invoke the _cache:get()_ function for every keys (begin from first that was added to the cache).

Additional Details & Logs

• Kong version: 0.11.1
• Operating System: CentOS 7
• Kong logs: LOGS

[hishamhm]

@RobertMlo Hi! I managed to reproduce your scenario, with no need to set TTL or LRU_SIZE. This is my assessment of what is happening:

kong.cache is backed by kong.mlcache, which uses resty.lrucache for Lua VM cache and ngx.shared.DICT for shm cache. In the implementation of the set operation of ngx.shared.DICT we have the following:

When it fails to allocate memory for the current key-value item, then set will try removing existing items in the storage according to the Least-Recently Used (LRU) algorithm. Note that, LRU takes priority over expiration time here. If up to tens of existing items have been removed and the storage left is still insufficient (either due to the total capacity limit specified by lua_shared_dict or memory segmentation), then the err return value will be no memory and success will be false.

So, what's happening is that:

1. before the custom plugin hits, the kong cache contains various small objects.
2. Then, you store one big 100M object in the cache, both the Lua cache and the shm.
3. When you try to store the second one, ngx.shared.DICT:set finds no free space, so it tries to evict items to make space. It tries "tens of existing items", but it only removes Kong's other small objects, so it finds no space and fails with "no memory".
4. When you try to store the third one, ngx.shared.DICT:set finds no free space, so it tries to evict items to make space. With the small objects out of the way, it will try evicting the first 100M object from the shm, and will succeed. It stores the third object in both Lua cache and shm. The Lua cache now contains objects 1 and 3; shm contains object 3.
5. Same for the fourth object. The Lua cache now contains objects 1, 3 and 4; shm contains object 4.
6. ...and so on.

If you increase the shm to be able to store 2 big objects, the third store will fail and you'll get objects 1, 2, 4, 5... If you reduce LRU_SIZE to 1, you will observe that stores 1, 3, 4, 5... will succeed, but in the end only the last element will be available from the cache.

So, in the end the strange behavior is explainable:

• kong.cache only reports a success if a callback succeeds in storing data in the shm (even if it would have been able to store it in the Lua cache). @thibaultcha, could you confirm if this is the desired behavior?

[thibaultcha]

This is indeed the intended behavior. The Lua cache is a "nice to have", but a value is considered "truly cached" only when it is in the shm for various reasons.

First of all, I would highly discourage the usage of the Kong-provided cache (or mlcache, or lua-resty-lrucache) to cache such large items. 100MB * 10 is already approaching half of the maximum LuaJIT VM memory limit, and is a great way to crash your OpenResty/Kong application with OOM errors.

This is the typical scenario we see emerging (with the famous "no memory" error) as more and more people are trying to use the cache to put values with sizes of different order of magnitude...

[hishamhm]

Thanks @thibaultcha for the words of wisdom! Given the mystery is solved, I guess we can close the issue. :+1:

[RobertMlo]

@hishamhm, @thibaultcha Thanks for explaining. It's very helpful.

@hishamhm I know that there is no need to set LRU_SIZE to reproduce that, but it was easier to investigate the cache behaviour with a small amount of iteration.

@thibaultcha I'd like to cache files seldom and they will have less than 1 MB size. I set 100 MB here, because I'm just verifying border cases to understand how the cache behaves in these cases ;)

As I understood:

1) The size of L2 (shm) cache is determined by a MEM_CACHE_SIZE parameter, while the size of L1 (Lua cache) is contained in the Lua VM, right?

2) I only got the TTL for the last cached value (during interation through my ten keys in step 6), because the cache:probe(key) function refers to L2 (where we find only one large cached file, the last added) instead of L1 where we find the rest large cached files. Could you confirm that?

[hishamhm]

@RobertMlo

1. Yes. L1 is limited by number of items, not size in bytes (it is of course restricted by LuaJIT's memory limitations).
2. Yes, cache:probe only probes L2.