Cache block time in Blockstore by CriesofCarrots · Pull Request #11955 · solana-labs/solana

CriesofCarrots · 2020-08-31T23:15:37Z

Problem

The getBlockTime rpc endpoint can return null for a block that hasn't been pruned from Blockstore. This is because we only keep the last 5 epochs of stake info, and stake info is needed for calculating a block timestamp on demand.

To address this problem, and generally offer better block-time support, we've made two changes to the original design (https://docs.solana.com/implemented-proposals/validator-timestamp-oracle):

The initial design called for block times to be calculated on demand in order to demonstrate that they are deterministic from the ledger. Caching block times saves this unnecessary every-call work; the block times are still deterministic from the ledger.
The initial design called for validators to vote every ~30min (4500 slots) in order to save space in Vote transactions. As of Submit a vote timestamp every vote #10630 , validators are now timestamp every Vote. As a result, there are plenty of timestamps available to calculate a stake-weighted timestamp as soon as a block is rooted in Blockstre.

Summary of Changes

Add Blockstore column family to cache blocktimes
Add CacheBlockTimeService, triggered from ReplayStage::handle_votable_bank, to calculate and cache a block's timestamp as soon as a block is rooted
Use cache in getBlockTime rpc
Add block_time to ConfirmedBlock when populated

Fixes #10089
Note: blocks before this PR is released may still return null

mvines · 2020-08-31T23:26:24Z

+        let slot_duration = slot_duration_from_slots_per_year(bank.slots_per_year());
+        let epoch = bank.epoch_schedule().get_epoch(bank.slot());
+        let stakes = HashMap::new();
+        let stakes = bank.epoch_vote_accounts(epoch).unwrap_or(&stakes);
+
+        if let Err(e) = blockstore.cache_block_time(bank.slot(), slot_duration, stakes) {
+            error!("cache_block_time failed: slot {:?} {:?}", bank.slot(), e);
+        }


How expensive is this? Maybe wrap a measure around it?

The pieces of this are measured in get_timestamp_slots() and cache_block_time(). You looking for a sum?

I was just more wondering if we run into issues of being able to keep up with the new slots as they come in. But if this operation takes 1-10ms or so then no worries

Empirical data suggests this operation will be in the 2-10ms range for current mainnet-beta throughput. However, it does depend on deserializing blocks to find vote transactions, and that deserialization definitely takes longer as TPS increases. (With about 10k TPS, I was seeing this take about 10x as long on my under-powered GCE instance.) One solution would be to index vote transactions/timestamps in blockstore to avoid the deserialization altogether; possibly as part of the transaction-status-service. I think that could be a follow-up optimization. Wdyt? @mvines

Ok cool, that seems fine for now. But how about this:

Move the recv_timeout() out of cache_block_time()

In the main thread loop, wrap a measure around cache_block_time(). Then if cache_block_time() takes longer than IDK, 100ms or so, emit a warn! or error! log.

Since this is an unbounded channel, if cache_block_time() ever does get backed up and roots start coming in faster than it can process then we have a memory leak and will probably eventually OOM. It'd be nice to get yelled at from the log if this ever starts happening

Sounds like a plan

How does this look? d0a0f50

codecov · 2020-09-01T02:42:59Z

Codecov Report

Merging #11955 into master will increase coverage by 0.0%.
The diff coverage is 93.1%.

@@           Coverage Diff            @@
##           master   #11955    +/-   ##
========================================
  Coverage    82.0%    82.0%            
========================================
  Files         337      338     +1     
  Lines       79225    79332   +107     
========================================
+ Hits        65011    65124   +113     
+ Misses      14214    14208     -6

CriesofCarrots · 2020-09-01T18:01:59Z

I rolled in adding block_time to ConfirmedBlock because it was a one-liner, which brought along block_time -> bigtable for free :)
Holding off on deprecating getBlockTime for now: #10089 (comment)

CriesofCarrots · 2020-09-01T18:02:04Z

@mvines Anything more you'd like to see here?

mvines · 2020-09-04T22:02:56Z

+        let slot_duration = slot_duration_from_slots_per_year(bank.slots_per_year());
+        let epoch = bank.epoch_schedule().get_epoch(bank.slot());
+        let stakes = HashMap::new();
+        let stakes = bank.epoch_vote_accounts(epoch).unwrap_or(&stakes);
+
+        if let Err(e) = blockstore.cache_block_time(bank.slot(), slot_duration, stakes) {
+            error!("cache_block_time failed: slot {:?} {:?}", bank.slot(), e);
+        }


I was just more wondering if we run into issues of being able to keep up with the new slots as they come in. But if this operation takes 1-10ms or so then no worries

…ightly

CriesofCarrots · 2020-09-09T15:33:08Z

Post-merge comments welcome

* Add blockstore column to cache block times * Add method to cache block time * Add service to cache block time * Update rpc getBlockTime to use new method, and refactor blockstore slightly * Return block_time with confirmed block, if available * Add measure and warning to cache-block-time

* Submit a vote timestamp every vote (#10630) * Submit a timestamp for every vote * Submit at most one vote timestamp per second * Submit a timestamp for every new vote Co-authored-by: Tyera Eulberg <tyera@solana.com> * Timestamp first vote (#11856) * Cache block time in Blockstore (#11955) * Add blockstore column to cache block times * Add method to cache block time * Add service to cache block time * Update rpc getBlockTime to use new method, and refactor blockstore slightly * Return block_time with confirmed block, if available * Add measure and warning to cache-block-time Co-authored-by: Michael Vines <mvines@gmail.com>

CriesofCarrots requested a review from mvines August 31, 2020 23:15

mvines reviewed Aug 31, 2020

View reviewed changes

CriesofCarrots force-pushed the cache-block-time branch 2 times, most recently from ec4453f to a346ced Compare August 31, 2020 23:35

CriesofCarrots commented Aug 31, 2020

View reviewed changes

Comment thread ledger/src/blockstore.rs

CriesofCarrots force-pushed the cache-block-time branch from a346ced to b72f12d Compare September 1, 2020 00:05

CriesofCarrots added CI Pull Request is ready to enter CI and removed CI Pull Request is ready to enter CI labels Sep 1, 2020

solana-grimes removed the CI Pull Request is ready to enter CI label Sep 1, 2020

CriesofCarrots force-pushed the cache-block-time branch from b72f12d to 5bb49ae Compare September 1, 2020 01:00

mvines mentioned this pull request Sep 4, 2020

validator: Add --enable-bigtable-ledger-upload flag #12040

Merged

mvines reviewed Sep 8, 2020

View reviewed changes

CriesofCarrots force-pushed the cache-block-time branch from 2263558 to 80bfc10 Compare September 8, 2020 15:48

Tyera Eulberg added 5 commits September 8, 2020 14:14

Add blockstore column to cache block times

e663f05

Add method to cache block time

317eaf4

Add service to cache block time

a3a6131

Update rpc getBlockTime to use new method, and refactor blockstore sl…

733e053

…ightly

Return block_time with confirmed block, if available

8572ed2

CriesofCarrots force-pushed the cache-block-time branch from 80bfc10 to 8572ed2 Compare September 8, 2020 20:18

Add measure and warning to cache-block-time

d0a0f50

CriesofCarrots merged commit 05db41f into solana-labs:master Sep 9, 2020

CriesofCarrots mentioned this pull request Sep 23, 2020

block cleaned up, it does not exist on node #12413

Closed

CriesofCarrots mentioned this pull request Sep 23, 2020

v1.3: Backport block time updates #12423

Merged

jstarry mentioned this pull request Sep 24, 2020

web3: Differentiate between getBlockTime errors #11963

Closed

CriesofCarrots deleted the cache-block-time branch September 24, 2020 19:19

Conversation

CriesofCarrots commented Aug 31, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Problem

Summary of Changes

Uh oh!

Uh oh!

mvines Aug 31, 2020

Choose a reason for hiding this comment

Uh oh!

CriesofCarrots Aug 31, 2020

Choose a reason for hiding this comment

Uh oh!

mvines Sep 4, 2020

Choose a reason for hiding this comment

Uh oh!

CriesofCarrots Sep 8, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

mvines Sep 8, 2020

Choose a reason for hiding this comment

Uh oh!

CriesofCarrots Sep 8, 2020

Choose a reason for hiding this comment

Uh oh!

CriesofCarrots Sep 8, 2020

Choose a reason for hiding this comment

Uh oh!

Uh oh!

codecov Bot commented Sep 1, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Codecov Report

Uh oh!

CriesofCarrots commented Sep 1, 2020

Uh oh!

CriesofCarrots commented Sep 1, 2020

Uh oh!

Uh oh!

mvines Sep 4, 2020

Choose a reason for hiding this comment

Uh oh!

CriesofCarrots commented Sep 9, 2020

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

CriesofCarrots commented Aug 31, 2020 •

edited

Loading

CriesofCarrots Sep 8, 2020 •

edited

Loading

codecov Bot commented Sep 1, 2020 •

edited

Loading