Introduce minimalistic ttl eviction for Recycler/PinnedVec #15139

ryoqun · 2021-02-05T13:29:27Z

Problem

PinnedVec tends to leak indefinitely due to some past burst.

@sakridge could this also be a legimate leak aside from the Vec HashMap capacity leak? I don't think we need 5GB / 3GB heap data at any given moment to run validator...

The recyclers just allocate to cover the transitional load and don't size down generally. Potentially we can size down with some heuristic if we can detect there is too much being held onto.

Summary of Changes

Amortized very-lightweight (1 vdso call for writes, 1 vdso + 2 O(1) VecDeque ops + 1 T::drop() for reads) eviction at each read from Recycler only when there has been enough capacity for the last hour.

ryoqun · 2021-02-05T14:43:47Z

perf/src/recycler.rs

 use std::sync::atomic::{AtomicUsize, Ordering};
 use std::sync::{Arc, Mutex, Weak};
+use std::time::Instant;
+use std::{collections::VecDeque, sync::atomic::AtomicBool};


hehe, rustfmt became lazy. ;)

codecov · 2021-02-05T14:46:05Z

Codecov Report

Merging #15139 (6425e4a) into master (774416a) will decrease coverage by 0.0%.
The diff coverage is 96.1%.

@@            Coverage Diff            @@
##           master   #15139     +/-   ##
=========================================
- Coverage    79.5%    79.5%   -0.1%     
=========================================
  Files         402      402             
  Lines      102297   102342     +45     
=========================================
+ Hits        81416    81449     +33     
- Misses      20881    20893     +12

sakridge · 2021-02-05T17:48:03Z

Nice, this seems pretty good, any perf change with the vec-deque and extra checks?

sakridge · 2021-02-05T17:50:05Z

perf/src/recycler.rs

+                .gc
+                .lock()
+                .expect("recycler lock in pb fn allocate");
+            if let Some((oldest_time, _old_item)) = gc.front() {


Thought about maybe checking the length of gc here. Maybe the recycler is just not used in a while and we are popping an extra one where we only have a handful of entries (1-5).

yeah, nice addition! Also, I noticed we shouldn't pop and drop the last one. We can just recycle it.. ;) I chose 10 for no particular strong reason. I just felt expiring with 5 items sounded too aggressive.... just that.

yea, sounds good.

ryoqun · 2021-02-07T15:32:58Z

perf/benches/recycler.rs

+    }
+
+    bencher.iter(move || {
+        recycler.recycle_for_test(recycler.allocate("me"));


Nice, this seems pretty good, any perf change with the vec-deque and extra checks?

In summary, sadly this increased twice of fast path of recycle->allocate iteration around 70ns to 140ns. But, I think this shouldn't affect the overall cluster perf. (I'm running gcp system-performance-test to be sure).

In detail, simply changing to VecDeque increases around 10ns and calling Instance::now() twice increases around 30ns * 2 by recycle and allocate.

base: test bench_recycler ... bench: 73 ns/iter (+/- 22) only changed Vec => VecDeque collection type: test bench_recycler ... bench: 85 ns/iter (+/- 7) this pr: test bench_recycler ... bench: 144 ns/iter (+/- 19)

I think these numbers are reasonable. VecDec is basically Vec and it only incurs some small additional offset calculation so the order should be 10ns-20ns.

As for Instance::now, I think this is decent value as well, considering it's basically vdso call, recalling my vague perf number for it. xD

Also, I also think VecDeque is faster than BTreeMap or BinaryHeap implementation, although, I haven't tested.

This tested on my laptop and I know there is jitter. If you're curious, I can run more rigorous experiment in more clean room enviroment. :)

ok not bad, thanks.

ryoqun · 2021-02-07T15:37:43Z

As for the actual observation of leaks are fixed. I'm still running tested validator.. This takes a while.

ryoqun · 2021-02-07T15:38:32Z

perf/src/recycler.rs

+                        let (_, mut expired) = gc.pop_front().unwrap();
+                        // unref-ing recycler here is crucial to prevent
+                        // the expired from being recycled again via Drop,
+                        // lading to dead lock!


my test validator was bitten by this. T_T

rerunning it....

ryoqun · 2021-02-08T08:04:01Z

well, test validator survived running against mainnet-beta for a day without deadlocks. So, I think I fixed the bug.

Now testing running testnet via heaptrack to see leaks are really solved as a last check.

ryoqun · 2021-02-08T16:04:47Z

well it turned out, this fix doesn't fix the leak...... the gossip-receiver code doesn't recycle PinnedVecs at all actually. I'm trying to fix it as well.

ryoqun · 2021-02-08T16:04:51Z

well it turned out, this fix doesn't fix the leak...... the gossip-receiver code doesn't recycle PinnedVecs at all actually. I'm trying to fix it as well.

ryoqun · 2021-02-08T16:04:54Z

well it turned out, this fix doesn't fix the leak...... the gossip-receiver code doesn't recycle PinnedVecs at all actually. I'm trying to fix it as well.

ryoqun · 2021-02-08T16:06:14Z

well it turned out, this fix doesn't fix the leak...... the gossip-receiver code doesn't recycle PinnedVecs at all actually. I'm trying to fix it as well.

carllin · 2021-02-14T00:17:21Z

@ryoqun the reason this may not be recycling is because https://github.com/solana-labs/solana/pull/15139/files#diff-798271cb43dca47253c06d8ab6888d8bf4fb385fc8e74cc2cd70ac1b3b664ebfR93 checks the oldest element, but if I have N elements, then if:

I only need 1 element at a time
N-1 elements are always sitting in the queue

As long as I have N total allocations before the max eviction time passes, then every packet will be refreshed by the recycle logic https://github.com/solana-labs/solana/pull/15139/files#diff-798271cb43dca47253c06d8ab6888d8bf4fb385fc8e74cc2cd70ac1b3b664ebfR136 and nothing will be recycled

ryoqun · 2021-02-14T08:17:36Z

@ryoqun the reason this may not be recycling is because https://github.com/solana-labs/solana/pull/15139/files#diff-798271cb43dca47253c06d8ab6888d8bf4fb385fc8e74cc2cd70ac1b3b664ebfR93 checks the oldest element, but if I have N elements, then if:
1. I only need `1` element at a time

2. `N-1` elements are always sitting in the queue
As long as I have N total allocations before the max eviction time passes, then every packet will be refreshed by the recycle logic https://github.com/solana-labs/solana/pull/15139/files#diff-798271cb43dca47253c06d8ab6888d8bf4fb385fc8e74cc2cd70ac1b3b664ebfR136 and nothing will be recycled

@carllin Your understanding is mostly correct. Note that such N total allocations must be peak and at-all-once to void the intended eviction for unused inventry. That's because recyler are basically LIFO. So, recycler's inventory must be lent-over some other places at the same time, to reach to refresh the deepest VecDeque items.. Originally, I thought that it's enough to prevent mem leak due to some spikes. But I looks like my guess was off.

My current theory is that solana-receiver threads creates unbounded number of Packets out of Recycler and puts them in to the mpsc::Channel and solana-gossip couldn't keep with it?

ryoqun · 2021-02-14T08:19:14Z

Also, this bug looks like a classic buffer bloat. ;)

ryoqun · 2021-02-18T11:47:37Z

perf/benches/recycler.rs

+use test::Bencher;
+
+#[bench]
+fn bench_recycler(bencher: &mut Bencher) {


ryoqun · 2021-02-18T14:44:49Z

perf/src/recycler.rs

+            // expire if less than 10.
+            if gc.len() > MAX_INVENTORY_COUNT_WITHOUT_EXPIRATION {
+                if let Some((oldest_time, _old_item)) = gc.front() {
+                    if oldest_time.elapsed().as_secs() >= EXPIRATION_TTL_SECONDS {


ryoqun · 2021-02-24T09:56:04Z

closing in favor of #15320. :)

ryoqun requested a review from sakridge February 5, 2021 13:29

ryoqun added v1.4 and removed v1.4 labels Feb 5, 2021

ryoqun commented Feb 5, 2021

View reviewed changes

sakridge reviewed Feb 5, 2021

View reviewed changes

ryoqun added 2 commits February 7, 2021 23:50

Introduce minimalistic ttl eviction for Recycler/PinnedVec

dc5971a

Fix deadlock and add more tests/benches

6425e4a

ryoqun force-pushed the ttl-recycler-pinnedvec branch from e44daf5 to 6425e4a Compare February 7, 2021 14:51

ryoqun commented Feb 7, 2021

View reviewed changes

ryoqun marked this pull request as ready for review February 7, 2021 15:36

ryoqun requested a review from sakridge February 7, 2021 15:37

ryoqun commented Feb 7, 2021

View reviewed changes

This was referenced Feb 11, 2021

solana-validator leaks memory (but at very slow pace) #14366

Closed

Track RecycleStore basic stats with needed refactor #15291

Merged

ryoqun mentioned this pull request Feb 15, 2021

Add limit and shrink policy for recycler #15320

Merged

ryoqun commented Feb 18, 2021

View reviewed changes

ryoqun closed this Feb 24, 2021

ryoqun mentioned this pull request Feb 24, 2021

Introduce ttl eviction for RecycleStore #15513

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Introduce minimalistic ttl eviction for Recycler/PinnedVec #15139

Introduce minimalistic ttl eviction for Recycler/PinnedVec #15139

ryoqun commented Feb 5, 2021

ryoqun Feb 5, 2021

codecov bot commented Feb 5, 2021 •

edited

Loading

sakridge commented Feb 5, 2021

sakridge Feb 5, 2021

ryoqun Feb 7, 2021

sakridge Feb 7, 2021

ryoqun Feb 7, 2021 •

edited

Loading

sakridge Feb 7, 2021

ryoqun commented Feb 7, 2021

ryoqun Feb 7, 2021 •

edited

Loading

ryoqun commented Feb 8, 2021 •

edited

Loading

ryoqun commented Feb 8, 2021

ryoqun commented Feb 8, 2021

ryoqun commented Feb 8, 2021

ryoqun commented Feb 8, 2021

carllin commented Feb 14, 2021 •

edited

Loading

ryoqun commented Feb 14, 2021

ryoqun commented Feb 14, 2021

ryoqun Feb 18, 2021

ryoqun Feb 18, 2021

ryoqun commented Feb 24, 2021

Introduce minimalistic ttl eviction for Recycler/PinnedVec #15139

Introduce minimalistic ttl eviction for Recycler/PinnedVec #15139

Conversation

ryoqun commented Feb 5, 2021

Problem

Summary of Changes

ryoqun Feb 5, 2021

Choose a reason for hiding this comment

codecov bot commented Feb 5, 2021 • edited Loading

Codecov Report

sakridge commented Feb 5, 2021

sakridge Feb 5, 2021

Choose a reason for hiding this comment

ryoqun Feb 7, 2021

Choose a reason for hiding this comment

sakridge Feb 7, 2021

Choose a reason for hiding this comment

ryoqun Feb 7, 2021 • edited Loading

Choose a reason for hiding this comment

sakridge Feb 7, 2021

Choose a reason for hiding this comment

ryoqun commented Feb 7, 2021

ryoqun Feb 7, 2021 • edited Loading

Choose a reason for hiding this comment

ryoqun commented Feb 8, 2021 • edited Loading

ryoqun commented Feb 8, 2021

ryoqun commented Feb 8, 2021

ryoqun commented Feb 8, 2021

ryoqun commented Feb 8, 2021

carllin commented Feb 14, 2021 • edited Loading

ryoqun commented Feb 14, 2021

ryoqun commented Feb 14, 2021

ryoqun Feb 18, 2021

Choose a reason for hiding this comment

ryoqun Feb 18, 2021

Choose a reason for hiding this comment

ryoqun commented Feb 24, 2021

codecov bot commented Feb 5, 2021 •

edited

Loading

ryoqun Feb 7, 2021 •

edited

Loading

ryoqun Feb 7, 2021 •

edited

Loading

ryoqun commented Feb 8, 2021 •

edited

Loading

carllin commented Feb 14, 2021 •

edited

Loading