Skip to content

MemPostings.Delete(): make pauses to unlock and let the readers read#15242

Merged
jesusvazquez merged 3 commits intoprometheus:mainfrom
colega:mempostings-delete-with-pauses
Nov 5, 2024
Merged

MemPostings.Delete(): make pauses to unlock and let the readers read#15242
jesusvazquez merged 3 commits intoprometheus:mainfrom
colega:mempostings-delete-with-pauses

Conversation

@colega
Copy link
Copy Markdown
Contributor

@colega colega commented Oct 29, 2024

This introduces back some unlocking that was removed in #13286 but in a more balanced way, as suggested by @pracucci.

For TSDBs with a lot of churn, Delete() can take a couple of seconds, and while it's holding the mutex, reads and writes are blocked waiting for that mutex, increasing the number of connections handled and memory usage.

This implementation pauses every 4K labels processed (note that also compared to #13286 we're not processing all the label-values anymore, but only the affected ones, because of #14307), makes sure that it's possible to get the read lock, and waits for a few milliseconds more.

This introduces back some unlocking that was removed in prometheus#13286 but in a
more balanced way, as suggested by @pracucci.

For TSDBs with a lot of churn, Delete() can take a couple of seconds,
and while it's holding the mutex, reads and writes are blocked waiting
for that mutex, increasing the number of connections handled and memory
usage.

This implementation pauses every 4K labels processed (note that also
compared to prometheus#13286 we're not processing all the label-values anymore,
but only the affected ones, because of prometheus#14307), makes sure that it's
possible to get the read lock, and waits for a few milliseconds more.

Signed-off-by: Oleg Zaytsev <[email protected]>
Co-authored-by: Marco Pracucci <[email protected]>
Signed-off-by: Oleg Zaytsev <[email protected]>
@colega colega force-pushed the mempostings-delete-with-pauses branch from 0fee8a8 to b11d1df Compare October 29, 2024 16:55
Copy link
Copy Markdown
Contributor

@pracucci pracucci left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nice job. LGTM.

codesome
codesome previously approved these changes Oct 29, 2024
Copy link
Copy Markdown
Member

@codesome codesome left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM. But can we test it somewhere before merging to ~verify if this is doing the intended thing?

@machine424
Copy link
Copy Markdown
Member

machine424 commented Oct 30, 2024

I've always wanted to give go_sync_mutex_wait_total_seconds_total a try.

As main like a base (adding #15239 on top, then reverting it and adding #15242 on top)

I got:
Screenshot 2024-10-30 at 14 26 53

I see this patch reduces lock contention, but I'm also seeing, in this situation, for this setup, the benefit of concurrency that was introduced in #15239 and reverted.

The 3 instances were fed with:

./avalanche   --gauge-metric-count=98   --counter-metric-count=111   --histogram-metric-count=2   --histogram-metric-bucket-count=8   --native-histogram-metric-count=0   --summary-metric-count=9   --summary-metric-objective-count=4   --series-count=50   --value-interval=300   --series-interval=300   --metric-interval=300   --port=9001

and queried with:

while true; do
  curl -G http://localhost:8080/api/v1/query --data-urlencode 'query={__name__=~".+"}' &
  curl -G http://localhost:8080/api/v1/query --data-urlencode 'query={__name__=~".+"}' &

  curl -G http://localhost:8888/api/v1/query --data-urlencode 'query={__name__=~".+"}' &
  curl -G http://localhost:8888/api/v1/query --data-urlencode 'query={__name__=~".+"}' &

  curl -G http://localhost:9091/api/v1/query --data-urlencode 'query={__name__=~".+"}' &
  curl -G http://localhost:9091/api/v1/query --data-urlencode 'query={__name__=~".+"}' &

  sleep 1
done

The prometheus instances were run with GOMEMLIMIT=5GiB GOMAXPROCS=8

Signed-off-by: Oleg Zaytsev <[email protected]>
@colega
Copy link
Copy Markdown
Contributor Author

colega commented Nov 1, 2024

Thank you for testing this, @machine424, we also tested in our Mimir environment (runs same TSDB) and after experimenting a little bit, I pushed another change that would pause more often, every 512 deleted series.

Note that the previous change looked well under normal load, but in scenarios where there's a lot of series churn (we have instances with more than 750K series churning) the parallel approach is still not enough, as we'd still block all reads for seconds.

I'll try to gather some graphs of our test on Monday, but so far I'd say this is looking good.

colega added a commit to colega/prometheus that referenced this pull request Nov 2, 2024
The change introduced in prometheus#14307 was great for the performance of
MemPostings.Delete(): we know which labels we have to touch, so we just
grab the lock once and keep processing them until we're done.

While this is the best for MemPostings.Delete(), it's much worse for
other users of that mutex: readers and new series writes. These now have
to wait until we've deleted all the affected postings, which are
potentially millions. Our operation isn't so urgent, but we're not
letting other users grab the mutex.

While prometheus#15242 proposes a solution for this by performing small pauses
from time to time and letting other callers take the mutex, it still
doesn't address the elephant in the room: we're just doing too much
stuff with the write mutex being held, that's is exclusive time for us.
We can spread it longer over time, decreasing the impact, but the
overall exclusive time is the same, and we should try to address that.

What's the long operation we're doing while holding the write mutex?
We're filtering the postings list for each label by building a new one,
and looking up in a hashmap whether each one of those elements id
deleted. These lists are potentially tens or hundreds of thousands of
elements each one.

Why don't we build that list while holding just a RLock()? Well there's
a small issue with that: maybe a new series is added to the list after
we've built that filtered replacement postings list, and before we took
the write mutex. The good news is that postings are always appended
in-order to the list and we are the only ones who delete things from
that list, so if we just check whether the list grew, we can know for
sure if we're missing something.

Moreover we don't even need to rebuild the entire list if something was
added, we just need to add the extra elements that the list has now
compared to our snapshot.

Finally, one last thing to address is that with this approach we'd be
taking the write mutex once per affected label value again, which is a
lot, it causes too long compactions under lots of read pressure, and we
mitigated that in the past. We also can't just build all the replacement
builds and then swap them in one go: we would be referencing too much
memory there. It is true that while we're swapping there's still someone
referencing the old slice from some reader, but not at an arbitrary
scale: for a 2M series tsdb, label names which reference all series
(like the typical env=prod) as 16MB of postings each one (2M * 8B).

So we process labels in batches, with max 128 labels in a batch (so
ideally we take one write mutex per each 128 labels) and a maximum of
10*len(allpostings) max postings in the batch (in our example that would
be an extra 160MB allocated temporarily, which should be negligible in a
2M series instance.

Signed-off-by: Oleg Zaytsev <[email protected]>
@colega
Copy link
Copy Markdown
Contributor Author

colega commented Nov 2, 2024

While this improves the situation, we've seen that it's not a perfect solution and we still see some impacts on the reads while doing the compaction. I would like us to consider a different approach: #15310

Edit: that one still needs some more love, so I think we can proceed with merging this one, while I polish the other one.

Signed-off-by: Oleg Zaytsev <[email protected]>
@colega
Copy link
Copy Markdown
Contributor Author

colega commented Nov 4, 2024

As promised, some screenshots. We've deployed the new image around Oct 31st at 13 UTC:

This is the go_sync_mutex_wait_total_seconds_total metric:

image

And the p99 reads latency has improved as well:

image

Copy link
Copy Markdown
Contributor

@pracucci pracucci left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks Oleg for this work! It helped really a lot (as screenshots show).

Copy link
Copy Markdown
Member

@jesusvazquez jesusvazquez left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM It seems a straightforward change that has brought some good results for downstream projects using the TSDB.

I see that both Thanos and Mimir have already taken this commit in so I see no reason to hold it further.

@jesusvazquez jesusvazquez merged commit b1e4052 into prometheus:main Nov 5, 2024
@colega
Copy link
Copy Markdown
Contributor Author

colega commented Nov 5, 2024

@machine424:

I've always wanted to give go_sync_mutex_wait_total_seconds_total a try.

Let's export that metric in Prometheus too (I was looking at it in Mimir, where it has been exported for a year).

#15339

juliusv pushed a commit that referenced this pull request Nov 5, 2024
…15242)

This introduces back some unlocking that was removed in #13286 but in a
more balanced way, as suggested by @pracucci.

For TSDBs with a lot of churn, Delete() can take a couple of seconds,
and while it's holding the mutex, reads and writes are blocked waiting
for that mutex, increasing the number of connections handled and memory
usage.

This implementation pauses every 4K labels processed (note that also
compared to #13286 we're not processing all the label-values anymore,
but only the affected ones, because of #14307), makes sure that it's
possible to get the read lock, and waits for a few milliseconds more.

Signed-off-by: Oleg Zaytsev <[email protected]>
Co-authored-by: Marco Pracucci <[email protected]>
narqo added a commit to grafana/mimir that referenced this pull request Nov 13, 2024
@verejoel
Copy link
Copy Markdown

Is there a chance we could backport this into 2.55? That way we could also patch this into Thanos quicker without having to upgrade to v3 of Prometheus.

verejoel pushed a commit to verejoel/prometheus that referenced this pull request Nov 27, 2024
…rometheus#15242)

This introduces back some unlocking that was removed in prometheus#13286 but in a
more balanced way, as suggested by @pracucci.

For TSDBs with a lot of churn, Delete() can take a couple of seconds,
and while it's holding the mutex, reads and writes are blocked waiting
for that mutex, increasing the number of connections handled and memory
usage.

This implementation pauses every 4K labels processed (note that also
compared to prometheus#13286 we're not processing all the label-values anymore,
but only the affected ones, because of prometheus#14307), makes sure that it's
possible to get the read lock, and waits for a few milliseconds more.

Signed-off-by: Oleg Zaytsev <[email protected]>
Co-authored-by: Marco Pracucci <[email protected]>
verejoel pushed a commit to open-ch/prometheus that referenced this pull request Dec 17, 2024
…rometheus#15242)

This introduces back some unlocking that was removed in prometheus#13286 but in a
more balanced way, as suggested by @pracucci.

For TSDBs with a lot of churn, Delete() can take a couple of seconds,
and while it's holding the mutex, reads and writes are blocked waiting
for that mutex, increasing the number of connections handled and memory
usage.

This implementation pauses every 4K labels processed (note that also
compared to prometheus#13286 we're not processing all the label-values anymore,
but only the affected ones, because of prometheus#14307), makes sure that it's
possible to get the read lock, and waits for a few milliseconds more.

Signed-off-by: Oleg Zaytsev <[email protected]>
Co-authored-by: Marco Pracucci <[email protected]>
yuchen-db pushed a commit to yuchen-db/prometheus that referenced this pull request Apr 30, 2025
…rometheus#15242)

This introduces back some unlocking that was removed in prometheus#13286 but in a
more balanced way, as suggested by @pracucci.

For TSDBs with a lot of churn, Delete() can take a couple of seconds,
and while it's holding the mutex, reads and writes are blocked waiting
for that mutex, increasing the number of connections handled and memory
usage.

This implementation pauses every 4K labels processed (note that also
compared to prometheus#13286 we're not processing all the label-values anymore,
but only the affected ones, because of prometheus#14307), makes sure that it's
possible to get the read lock, and waits for a few milliseconds more.

Signed-off-by: Oleg Zaytsev <[email protected]>
Co-authored-by: Marco Pracucci <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

6 participants