Potential Prometheus memory leak in ingesters

[roystchiang]

Describe the bug
We encountered an issue with Ingester/Prometheus unable to recover from WAL due to invalid block sequence: block time ranges overlap issue. Repeatedly calling this Ingester with ingestion request results in OOM.

When an ingester service starts up, it tries to recover TSDB for all UserIds. If a TSDB failed to be recovered, ingester will skip it and continue on. When an ingestion request for the corrupted TSDB comes, ingester will try to create a TSDB for this UserID. Since there is already a TSDB for this user, this action will result in Prometheus performing recovery once again.

I noticed that for the same request, ingesters log different errors

level=warn ts=2020-10-01T19:36:19.800983863Z caller=grpc_logging.go:38 method=/cortex.Ingester/Push duration=28.647562844s err="user=some-user-id: failed to open TSDB: /data/tsdb/some-user-id: invalid block sequence: block time ranges overlap: [mint: 1601488821086, maxt: 1601490567894, range: 29m6s, blocks: 2]: <ulid: 01EKG4DJNVRS9KSPQZHVHKD07G, mint: 1601481600000, maxt: 1601490567894, range: 2h29m27s>, <ulid: 01EKGQHG7FP40NRB4SA0GFAV4E, mint: 1601488821086, maxt: 1601496000000, range: 1h59m38s>" msg="gRPC\n"

level=warn ts=2020-10-01T19:15:41.737350414Z caller=grpc_logging.go:38 method=/cortex.Ingester/Push duration=13m46.278392928s err="user=some-user-id: failed to open TSDB: /data/tsdb/some-user-id: mmap files, file: /data/tsdb/some-user-id/chunks_head/000036: mmap: cannot allocate memory" msg="gRPC\n

I see the same chunk-head is memory-mapped about 200 times. I also saw that an ingester is able to handle about 200 requests for this corrupted TSDB before going OOM. I suspect Promethues is memory-mapping files during WAL replay. When Prometheus fails, this mmap is not cleaned up.

/ # sysctl vm.max_map_count
vm.max_map_count = 65530

/ # pmap 1 | wc -l
65523

/ # pmap 1 | grep /data/tsdb/some-user-id/chunks_head/000036 | wc -l
236

To Reproduce
Steps to reproduce the behavior:

1. Start Cortex (v1.4.0-rc.1)
2. Have a corrupted TSDB in ingester
3. Perform write operations for the corrupted TSDB
4. Ingester goes OOM

Expected behavior
Ingester should not go OOM

Environment:

• Infrastructure: AWS EKS
• Deployment tool: helm

Storage Engine

• Blocks
• Chunks

Additional Context

[codesome]

Opened prometheus/prometheus#8028, the fix for m-map explosion should go in Prometheus ideally.

[pstibrany]

Cortex should also not try to reopen "broken" TSDB on every push, but should remember that opening failed. IT should then export number of "bad" TSDBs via metric, so that it can be alerted on. If push comes for bad TSDB, it should be automatically rejected.

[codesome]

The fix for this issue in Prometheus is in progress and I expect it to be merged today/tomorrow. I will upgrade the Prometheus here after that.

[codesome]

It got merged in Prometheus (prometheus/prometheus@c5a832b) and this PR #3373 should get that fix into Cortex.

[pracucci]

Thanks @codesome for the update. I think there are two different issues in this PR:

1. The memory leak when TSDB open fails and you retry to open it multiple times. Prometheus PR you linked fixes it but I guess it was already implicitly fixed by Fail fast an ingester if unable to load existing TSDBs #3354
2. The root cause of invalid block sequence: block time ranges overlap, which is still to be investigated. Could you take a look at this?

[codesome]

I forgot to link the issues, but here are they

• /flush call on Cortex Blocks can result in overlapping blocks #3348
• TSDB can create overlapping blocks, race during forced compaction prometheus/prometheus#8055

They are my best guesses for now for the root cause and need to investigate further how that can be fixed, because force flushing goes against some assumptions of TSDB, which is, the compaction does not happen for the ingestible range (which is last 1hr)

[pracucci]

Given we suspect it's a race condition, I think the solution is easy in Cortex. I'm perfectly fine having an ingester in Cortex which rejects (not wait, like a lock) write requests with a 5xx if there's an ongoing forced flush (/ingester/flush) for that specific tenant.

Following this idea, if there's just one single ingester flushing, then there will be no impact on the cluster, because a 5xx from a single ingester is still OK when Cluster is running with a replication factor of 3 (quorum = 2). If you run the forced flush on all ingesters at the same time, the remote writes to the Cluster will return some 5xx and then Prometheus will retry.

[codesome]

I will work on a fix for that today on coming Tuesday Wednesday with the proposed solution