Elastic Snapshots cause out of memory exceptions

[ecovadis-devops]

Elasticsearch version (bin/elasticsearch --version): ECK 1.1.2 ELK 7.7.1

Plugins installed: [repository-azure]

JVM version (java -version): Default by ECK docker image

OS version (uname -a if on a Unix-like system): Default by ECK docker image

Description of the problem including expected versus actual behavior:
We run 8 ELK 7.7.1 clusters on ECK 1.1.2 on Azure AKS. They are of different sizes - with Heap size from 2 to 12 GB (heap size is always 50% of the available memory) and data size from 20 GB to 700 GB. All of them are usually healthy and have >~50% of heap size and disk size free.

We have automatic snapshot setup every ~6 hours on all of them. It happens randomly - one every few snapshots, on random instances, that the snapshot will cause heap memory to suddenly jump to 100%, cause OOM exception and crash at least one of cluster nodes (all clusters have 2 nodes).

It happens on big and small instances, but is not really predictable.
It seems that this issue started after an upgrade to ELK 7.7.1, earlier we run ECK 1.0 and ELK 7.6.1 and we did not notice this issue.

Steps to reproduce:

1. Setup an ECK 1.1.2 with ELK 7.7.1 cluster on Azure AKS with repository-azure plugin
2. Configure automatic snapshots - for instance every hour
3. Watch for sudden spikes in Heap Memory usage, happening exactly when the snapshot starts

Provide logs (if relevant):

[elasticmachine]

Pinging @elastic/es-distributed (:Distributed/Snapshot/Restore)

[matriv]

Do you see anything unusual in the logs?

[original-brownbear]

@ecovadis-devops

Watch for sudden spikes in Heap Memory usage, happening exactly when the snapshot starts

So this only affects the start of a snapshot. Once starting the snapshot has gone through cleanly things are stable heap wise?
Also, may I ask how many snapshots and shards per snapshot you approximately have in your repository?

[ecovadis-devops]

@ecovadis-devops

Watch for sudden spikes in Heap Memory usage, happening exactly when the snapshot starts

So this only affects the start of a snapshot. Once starting the snapshot has gone through cleanly things are stable heap wise?
Also, may I ask how many snapshots and shards per snapshot you approximately have in your repository?

Yes, it seems that heap issues happen only within first ~0-2 minutes of the snapshot. If there are no heap issues at the start of the snapshot, the whole process works just fine.

Our snapshot policy is set to do a snapshot every 6 hours, and keep them 7 days. This gives ~30 snapshots in the repo at any given time. On our biggest instance we have ~260 indices and ~330 shards. Snapshots usually take from 1 to 10 minutes to complete.

Do you think that keeping less snapshots in the repo, let's say 10 instead of 30, would help? I could do snapshots less frequently or keep them only for 2 days instead of 7.

[original-brownbear]

Do you think that keeping less snapshots in the repo, let's say 10 instead of 30, would help? I could do snapshots less frequently or keep them only for 2 days instead of 7.

In your use case we are dealing with fairly low numbers of shards + snapshots already, I would be surprised if the number of shards was the issue. I ran some experiments with massive amounts of shards (as in O(10k)) and ~100 snapshots when trying to reproduce this and could not get more than a couple of MB (<10) in snapshot related heap usage so I'm having a hard time reproducing this.

The easiest for me in tracking this down would be if you could provide a heap dump of a node that crashed because of such a spike in heap usage. (I could provide a way of sending it to me privately)
Second best (or in addition to a heap dump) it would be interesting to know the sizes of metadata blobs in your Azure repository.
Could you check and provide me with the sizes of the index-${N} blob at the root of your repository as well as the sizes of the index-${uuid} blobs in the shard paths (/indices/$index-id/$N/index-${uuid})? (I know it's 300, but maybe you can script this somehow ... what I'm mainly interested in if there's one that's very large (as in larger than a could of kb)).

[ecovadis-devops]

The easiest for me in tracking this down would be if you could provide a heap dump of a node that crashed because of such a spike in heap usage. (I could provide a way of sending it to me privately)

I understand how much help could this be. I need to learn first how to set up memory dump on ECK on AKS, and then I need to wait until the issue occurs. It will take few days.

Second best (or in addition to a heap dump) it would be interesting to know the sizes of metadata blobs in your Azure repository.
Could you check and provide me with the sizes of the index-${N} blob at the root of your repository as well as the sizes of the index-${uuid} blobs in the shard paths (/indices/$index-id/$N/index-${uuid})? (I know it's 300, but maybe you can script this somehow ... what I'm mainly interested in if there's one that's very large (as in larger than a could of kb)).

Please have a look at the attached file. It contains all index-* files from the repo sorted by Lenght in Bytes. The biggest ones are at the end - they are at most ~500KB.
data.txt

[original-brownbear]

Thanks so much @ecovadis-devops that list of files is quite helpful.

Looking at the raw numbers we have a few hundred kb for each shard's metadata (this data is compressed and in SMILE format). You said that this is happening in a 2 node cluster and we're seeing ~300 shards per snapshot.
So say we have 150 shards per node, this entails loading 150 * 100kb = 15MB of raw snapshot repo metadata. After decompressing, this could conceivably increase in size by an order of magnitude (there is some overhead for decompression, deserialization and the like). I wonder if due to #51729 and other optimizations we may be holding on to more bytes concurrently than in 7.6.x here and that's why you're seeing that spike.

Given how there seems to be only ~900M of free heap after the initial spike it's conceivable that every now and then you get unlucky and the combination of doing heavy IO (Azure SDK allocates relatively large buffers frequently) and loading a bunch of
metadata could tip a node over the edge every now and then.

I will leave this issue open and will see what I can do about increasing the efficiency of the logic here to be a little less memory hungry. In the mean time you could try retaining fewer snapshots and see if that helps. If it does help, then my above theory makes good sense I think and improvements like #60201 should make things significantly more stable.