eth/downloader: fix skeleton cleanup

[rjl493456442]

This pull request fixes a corner case in skeleton header deletion.

The background is Geth uses a backward-sync mechanism to fetch and assemble the skeleton header chain locally (guided by consensus client) and then extend block chain by consuming the skeleton headers. The consumed skeleton headers will be deleted from database to avoid accumulating junks.

The assumption is always held that a complete skeleton header chain is linked with local blockchain, specifically skeleton.tail.parent == blockchain.head. However the originally deletion logic always sets the blockchain.head as the new tail and delete headers beforehand.

In this fix, the next header of filled block will be regarded as the new tail, to keep the guarantee skeleton chain is linked with blockchain, instead of overlapping with it.

It's not a really critical issue because we just leave one more skeleton header in database, but it will result in some weird behaviors which we really want to avoid.

---

A: Avoid unexpected chain truncation

Before spinning up a new sync cycle, downloader needs to figure out the common ancestor of local chain and skeleton header chain by function findBeaconAncestor.

Due the fact that originally deletion logic sets the tail with the local chain head, the common ancestor will be chain.head-1.

Therefore, the excess block along with its other data(e.g. receipts) will be truncated from the ancient store by this logic

	        // Rewind the ancient store and blockchain if reorg happens.
		if origin+1 < frozen {
			if err := d.lightchain.SetHead(origin); err != nil {
				return err
			}
			log.Info("Truncated excess ancient chain segment", "oldhead", frozen-1, "newhead", origin)
		}

This behavior is really unexpected in normal cases, should only occur if the network reorg is deeper than our local chain.
Unfortunately It occurs a lot, e.g.

Nov 15 18:21:30 ip-10-0-0-11.ec2.internal geth[18425]: INFO [11-15|18:21:30.426] Syncing beacon headers                   downloaded=18,579,869 left=3,223,551  eta=5m40.255s
Nov 15 18:21:30 ip-10-0-0-11.ec2.internal geth[18425]: ERROR[11-15|18:21:30.428] Reject duplicated disable operation
Nov 15 18:21:30 ip-10-0-0-11.ec2.internal geth[18425]: WARN [11-15|18:21:30.430] Rewinding blockchain to block            target=3,223,551
Nov 15 18:21:33 ip-10-0-0-11.ec2.internal geth[18425]: INFO [11-15|18:21:33.424] Loaded most recent local header          number=3,223,551  hash=a0aaff..914938 td=146,234,259,464,463,532,817 age=6y9mo4w
Nov 15 18:21:33 ip-10-0-0-11.ec2.internal geth[18425]: INFO [11-15|18:21:33.424] Loaded most recent local block           number=0          hash=d4e567..cb8fa3 td=17,179,869,184              age=54y7mo3w
Nov 15 18:21:33 ip-10-0-0-11.ec2.internal geth[18425]: INFO [11-15|18:21:33.424] Loaded most recent local snap block      number=3,223,551  hash=a0aaff..914938 td=146,234,259,464,463,532,817 age=6y9mo4w
Nov 15 18:21:33 ip-10-0-0-11.ec2.internal geth[18425]: INFO [11-15|18:21:33.424] Loaded last snap-sync pivot marker       number=18,578,974
Nov 15 18:21:33 ip-10-0-0-11.ec2.internal geth[18425]: ERROR[11-15|18:21:33.424] Failed to reset txpool state             err="missing trie node d7f8974fb5ac78d9ac099b9ad5018bedc2ce0a72dad1827a1709da30580f0544 (path ) layer stale"
Nov 15 18:21:33 ip-10-0-0-11.ec2.internal geth[18425]: ERROR[11-15|18:21:33.424] Failed to reset blobpool state           err="missing trie node d7f8974fb5ac78d9ac099b9ad5018bedc2ce0a72dad1827a1709da30580f0544 (path ) layer stale"

I think we can avoid it by applying this fix.

---

B: Annoying error log for deleting skeleton headers

Failed to clean stale beacon headers err="filled header below beacon header tail: 16554016 < 16554017"

This kind of log is pretty common and I realized that the filled header is just one block before the tail. My hunch is we spin up the backfiller but terminate it without extending any blocks into the local chain. It can be avoid with this fix.

[holiman]

This looks good to me, but it's really one of these PRs where the effects are non-trivial. Maybe @karalabe can review, or we'll need to have a quick chat about it

[karalabe]

I'm unsure that this is correct.

Number is the last item newly filled. When I start a sync loop, lets say I have N blocks in my chain. Then I skeleton sync, and will reconstruct headers from HEAD to N+1, and which point I have my subchain linked to the local chain.

I start backfilling. If I fail to fill anything, cleanStales does not get called. If I successfully fill 1 block, then filled will be N+1 (the newly filled one block).

In that case number == filled == N+1, which is == s.progress.Subchains[0].Tail. The only way to hit this error would be to backfill something we already had in our chain.

With the proposed modification however, backfilling my local head block would make the check pass, but that should not be possible, because I can only backfill stuff from my subchain, not 1 block below it.

[rjl493456442]

If I fail to fill anything, cleanStales does not get called

I am not sure about it. cleanStales will be invoked anyway regardless if we successfully fill something or not. The CurrentSnapBlock() will be returned as the newly filled block.

Thus it's theoretically possible (1) the tail is N+1 and (2) filled is N, the error will be reported.

[karalabe]

According the below, the will only call cleanStales if something was filled.

			if filled := s.filler.suspend(); filled != nil {
				// If something was filled, try to delete stale sync helpers. If
				// unsuccessful, warn the user, but not much else we can do (it's
				// a programming error, just let users report an issue and don't
				// choke in the meantime).
				if err := s.cleanStales(filled); err != nil {
					log.Error("Failed to clean stale beacon headers", "err", err)
				}
			}

That said, you are also right that resuming the filler will always return the head snap block (or genesis I guess in case we're brand new).

		defer func() {
			b.lock.Lock()
			b.filling = false
			b.filled = b.downloader.blockchain.CurrentSnapBlock()
			b.lock.Unlock()
		}()

Interesting, I guess this was a refactor after I designed the original idea. It kind of makes the filled check in my first code segment moot.

[karalabe]

Ok, I agree with this +1, but we need to fix some comments that mention that it cannot happen. Namely,

• https://github.com/ethereum/go-ethereum/blob/master/eth/downloader/beaconsync.go#L52

  • // suspend cancels any background downloader threads and returns the last header
    // that has been successfully backfilled (potentially in a previous run), or the genesis.

• https://github.com/ethereum/go-ethereum/blob/master/eth/downloader/skeleton.go#L164

  • // The method should return the last block header that has been successfully
    // backfilled (in the current or a previous run), falling back to the genesis.

• https://github.com/ethereum/go-ethereum/blob/master/eth/downloader/skeleton.go#L385
  • We should add an error log if the filled is nil (vs the current code that checks for non-nil-ness as a happy path only).

[karalabe]

Ah hmm, indeed this is wonky. If the tail is the first "missing" header, then it should be filled+1

[karalabe]

This comment is not valid any more. The new tail might be either filled (if the HEAD itself was filled) or filled+1 if something earlier was filled. This is problematic for L1159, which sets the Head to number. In that case, you could end up with Tail > Head.

L1164 also feels broken with the fixed logic because we're writing filled as a skeleton header, but that's not the case any more if it was just filled. This might arguably be broken even in the current code, but it's at least uniformly broken. With the new code, you can end up with a skeleton header of filled, but maybe a Tail of filled+1, which is inconsistent.

[rjl493456442]

Sorry I don't get it. I don't think it's possible to have HEAD as filled but TAIL as filled+1.

In the case of filling everything, both HEAD and TAIL should be set to filled in the new logic right?

[karalabe]

This is problematic. newTail can either be filled or filled+1, but the code below acts as if it were one or the other. It would be very hard to reason about.

IMO if the happy path is filled+1, then we should special case filled and have a condition that does all the cleanups necessary for "filling the entire subchain"' then we can have the remainder of the code handle the partial fill scenario.

Handling both cases together below makes the code very hard to digest IMO.

[rjl493456442]

I am wondering if we fill the whole chian, should we delete the skeleton chain totally? Theoretically it's the best way to handle the case, just need to confirm the non-existent skeleton won't break the other part.

[rjl493456442]

@karalabe I updated the cleanup logic, not sure if this version is easier to understand. Please take another look.

[rjl493456442]

It turns out this error is never reported during the snap sync, after did occur all the time after the initial sync.

[fjl]

Wait, we still haven't merged this!?

[fjl]

@karalabe PTAL

[karalabe]

Whilst I agree that this clause is an error as it should never happen, wondering if returning an error could end up getting stuck in some weird way if a bug is hit vs. being able to self recover if we blindly delete the "overlapping" stuff that was side-filled?

[rjl493456442]

I guess the worst case is we keep all the skeleton headers in database, but the normal sync procedure won't be aborted/stuck?

I will probably prefer to print out the error now and to see if anyone really meet this very situation.

[rjl493456442]

I have addressed the comments, @karalabe , please take another look!

[karalabe]

SGTM