Fix consensus bug from deleting account in same block that creates it #1913

carver · 2020-01-29T19:49:13Z

What was wrong?

Fix #1912

How was it fixed?

The bug was: when a previous transaction creates/modifies an account,
and then is "locked", those pending changes are written at the end of the block, even if the
account is deleted is a subsequent transaction.

The fix was: clear out all "locked" storage changes (those made during previous transactions) when you lock in an account deletion.

That fix brought up a new interesting case, where the "dirty" flag wasn't noticing when an account started the block as empty, then some storage was added in one transaction, then in a later transaction it was deleted again. The further solution was to track a history of of storage tries that can be reverted to (a new one added on every account delete), and generously treat the storage as dirty if there were ever any writes in the block, even if the trie currently has the same state root as the root was at the beginning of the block.

To-Do

Clean up commit history
more documentation
Add entry to the release notes

Cute Animal Picture

eth/db/storage.py

carver · 2020-01-30T00:57:00Z

Well, making progress: Block 116526 is now importing!

... but it only got to 116530 before failing again 🤦‍♂️

I'll wait to figure that out before posting this for review.

It's pretty concerning that we're getting all these consensus bugs while still passing the ethereum/tests! ☹️

veox · 2020-01-30T12:51:50Z

tests/core/vm/test_vm_state.py

+    state.lock_changes()
+    assert state.get_storage(ADDRESS, 0) == 0
+
+    # delete account in next "transaction"


Minor: probably meant to say "revive" instead of "delete".

veox · 2020-01-30T13:49:22Z

Block #116530 is very similar: calls are made to create and destroy contracts... Not sure what's different from the previous one, I'll take a look now.

veox · 2020-01-30T14:42:06Z

Well, making progress: Block 116526 is now importing!

It's #116525 there was trouble with... Are you sure you didn't import that using some other code by accident (e.g. f4cba85)? Because I'm trying Trinity (at current master) with this PR's branch (at 86be04f), and am still failing to import #116525.

Although 86be04f does help py-evm pass the test in 16a9b34.

I've made sure that my Trinity installation indeed has the changes from py-evm's 86be04f in its virtualenv dependency... Not sure what's going on here.

pipermerriam · 2020-01-30T17:53:40Z

I think we may be near a point where we need to pay down tech debt in this area. It seems we've ended up with lots of layers here and I at least am having a lot of difficulty reasoning about how we manage all of the nuances related to updating account and contract state.

carver · 2020-01-30T19:14:54Z

It's #116525 there was trouble with... Are you sure you didn't import that using some other code by accident (e.g. f4cba85)?

No, you're right. I had imported it using the old code and skipped over it during sync.

carver · 2020-01-30T23:18:42Z

I think we may be near a point where we need to pay down tech debt in this area. It seems we've ended up with lots of layers here and I at least am having a lot of difficulty reasoning about how we manage all of the nuances related to updating account and contract state.

I'm also not happy with how complex the code is, and it being a pain to debug.

Some key things that seem to be interacting in a complex way are:

queuing up all the state changes without writing to the trie
state changes can be reverted back to the beginning of a transaction, but not across transaction boundaries
when storage tries are deleted, it changes the storage root hash on the same timeline as the other storage changes. The root hash change must be revertable, in lock-step with all the other storage changes.
thinking through pre and post Byzantium: whether you have to flush the changes to the trie at each transaction, or only at the end of the block

With all those interacting factors above, I have no immediate idea how to make it better. One option is to push the complexity into JournalDB, to make it trie-aware (to handle root hash changes) and boundary-aware (to handle changes that cannot be reverted, from previous transactions). I think that's just pushing complexity around, doesn't really seem like an improvement. I would probably need a solid chunk of time to really reset my mind on how to design it a whole new way.

carver · 2020-01-30T23:20:06Z

But some good news! The latest push actually does import block 116525, and is at 153492 and continuing...

carver · 2020-01-31T01:01:19Z

Wow, a shocking number of consensus bugs that are not covered by ethereum/tests.

Found the next failed import at block #336508. Pretty interesting, only the receipt root is broken:

 - header.receipt_root:
    (actual)  : b'\xfd\x03\xd3\xd3<\x9e\xf9\xc5\xed\xde\x02aW\xd5J\xe3\xa1\xed\x0c\x85,N\\\x13d\xb2\xa6`\xf4\xa0\x9eo'
    (expected): b'\xbfk\xb0>X\x19r\xe1A\xb4\xcf\xc2\x13X\xdf\xbdDQ\xff\xbe\xfa\xb1P6\xbe\x93\xd1&_\xb2^\x14'

eth/db/storage.py

veox · 2020-01-31T14:04:00Z

Found the next failed import at block #336508.

Verified - indeed!

JIC, I've checked with py-evm back at master, too - the issue persists. So, it's an existing bug, not a regression in this PR.

Reverting to known "good" Trinity and py-evm (at v0.2.0a42) allows the sync to continue, importing block #336508 and beyond (ran for 10 minutes, at least up to #346858).

Re-setting to block #336507 and switching py-evm to "bad" v0.2.0a43 results in import failure ("mix hash mismatch"), which among other things shows the same incorrect receipt_root as above (b'\xfd\x03..\xa0\x9eo').

In other words, the regression lies somewhere in the same py-evm update, v0.2.0a42 to v0.2.0a43. I haven't yet verified that the culprit is also PR #1735.

veox · 2020-01-31T16:04:50Z

I'm checking the intermediate state_roots for each transaction receipt; in block #336508, there are 5 txs; at indexes 0, 1, 3, 4 are calls to setAvatar(uint256,bytes) (of a contract I didn't review); at index 2, there is the call to deleteAllAvatars().

state_root at index 2 doesn't match:

geth says it's 0xf1af37b9b975c2626d3b07ad995f06d5286af983d3b5f0ac0a0ff47bf0e1d098;
trinity says it's 0x39e4b7faa521431a15be1007fb19e9d386c057bde21917520f84312e2e2ac442.

state_root in all other (four) receipts matches.

FTR, trinity produces these (no 0x prefix here):

tx0 receipt state root: baf63127abe8f8445d98c137aeea39b77cbf1008ca41df31c3f63ba1f7add9aa
tx1 receipt state root: 5b2378dc119040215d6825f639fc097e000d01f902bda9cacaec17781194f772
tx2 receipt state root: 39e4b7faa521431a15be1007fb19e9d386c057bde21917520f84312e2e2ac442
tx3 receipt state root: c5b12436b28674f895b4158abd1b2326c590aca5f37e896ad38200c73e309aa6
tx4 receipt state root: c112806aedc65b2256714051c8178556d203daf0ea626fe37c9638407d0d763e

As to what's going on: the most likely reason we're not getting a state_root mismatch for the block: the deleted data in the contract's storage is overwritten (within the same block), and the resulting state is as expected. It's just the intermediate state that's "wrong" - or, to be more specific, its root seems to be miscalculated.

eth/db/storage.py

carver · 2020-01-31T19:42:35Z

As to what's going on: the most likely reason we're not getting a state_root mismatch for the block: the deleted data in the contract's storage is overwritten (within the same block), and the resulting state is as expected.

Looks like it's even simpler than that: AccountDB isn't recognizing the storage as having changed, so it doesn't try to write out the new storage root to the account. (Note there is no Updating account 0x5dc2e401e29ea16e51ebcecaef129c15fed5a5e8 to storage root X line at the end of the transaction at index 2). Why it's not recognizing the storage as changed is currently a mystery. (ie~ AccountStorageDB.has_changed_root is returning False) I'm digging in now...

carver · 2020-01-31T20:24:23Z

Looks like it had to do with reverting the storage root back to the root at the beginning of the block, and not treating that as a change. By always treating the storage as changed, that fixes pre-Byzantium (but seems to break something in Istanbul's CREATE2).

carver · 2020-01-31T20:32:06Z

If the account is not created, and the new storage root is for empty storage, then we shouldn't create the account just to put a blank storage root in it.

carver · 2020-01-31T20:53:24Z

carver · 2020-01-31T23:55:17Z

So maybe come back for a refactor later, after we get sync reliable and trinity to mvp. Thoughts @pipermerriam ?

carver · 2020-02-01T01:22:50Z

@cburgdorf Seems worth double-checking that this fix also fixes the goerli test you ran. How did you set that up again and/or are you up for re-running it against this branch?

cburgdorf · 2020-02-01T02:27:48Z

I'm on vacation without laptop but just running `trinity --goerli --sync-mode full` should be all you need. I don't know the exact block that broke but if you get past 300k blocks it definitely fixed that bug. I'm sure @veox can also assist.

…

On Sat, Feb 1, 2020, 08:22 Jason Carver ***@***.***> wrote: @cburgdorf <https://github.com/cburgdorf> Seems worth double-checking that this fix also fixes the goerli test you ran. How did you set that up again and/or are you up for re-running it against this branch? — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#1913?email_source=notifications&email_token=AAD7HFNXGJUW4OKDYVLD5GDRATFGVA5CNFSM4KNKPGKKYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEKQPQTQ#issuecomment-580974670>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AAD7HFLTP7664SHRJAKUAMTRATFGVANCNFSM4KNKPGKA> .

veox · 2020-02-01T09:49:29Z

Yup! I'll check this on main-net (from scratch), and then try to sync Goerli - that's where I started, after all.

veox · 2020-02-01T15:45:27Z

Confirming that the issue is no longer present when using py-evm from PR #1913.

Main-net blocks #116525 and #336508 imported successfully (I ran it up to #347457).

So has Goerli block #226323 (still running, #472783 ATM).

pipermerriam

👍

pipermerriam · 2020-02-06T20:22:11Z

eth/db/storage.py

@@ -120,7 +141,7 @@ def __delitem__(self, key: bytes) -> None:

    @property
    def has_changed_root(self) -> bool:
-        return self._write_trie and self._write_trie.root_hash != self._starting_root_hash
+        return self._write_trie


Assuming I'm correct that this is checking for the None value, I'd advocate for this to be return self._write_trie is not None.

pipermerriam · 2020-02-06T20:23:08Z

eth/db/storage.py

@@ -129,9 +150,9 @@ def get_changed_root(self) -> Hash32:
            raise ValidationError("Asked for changed root when no writes have been made")

    def _clear_changed_root(self) -> None:
+        self._starting_root_hash = self._write_trie.root_hash


If you get back in here could you maybe drop a comment or two in this method explaining in some detail why we do each of these things. Since it's not clear how to address some of the debt in the code, maybe we can address some of with with better comments.

pipermerriam · 2020-02-06T20:24:14Z

eth/db/storage.py

        self._trie_nodes_batch: BatchDB = None

+        # When deleting an account, push the pending write info onto this stack.
+        # May happen multiple times for multiple deletes.
+        self._historical_write_tries: List[Tuple[HexaryTrie, BatchDB, Hash32]] = []


Maybe make a NamedTuple for the inner value type here. Probably makes some of the other code a bit easier to read/grok.

pipermerriam · 2020-02-06T20:27:34Z

eth/db/storage.py

+        # Track how many times we have cleared the storage. This is journaled
+        # so that we can revert to an old clear count. The clear count is used
+        # as an index to find the base trie from before the revert.
+        self._clear_count = JournalDB(MemoryDB({CLEAR_COUNT_KEY_NAME: to_bytes(0)}))


Using the JournalDB here feels like it may be the wrong choice. Can this just be modeled using a list (stack) or somethng?

I updated the comment a bit to try to explain: it has to move in lockstep with the main storage journal, so we can detect when a revert crosses back over an account delete.

The bug was: when a previous transaction creates/modifies an account, and then is "locked", those pending changes are written even if the account is deleted is a subsequent transaction. The fix was: clear out all locked storage changes when you lock in an account deletion. This requires carefully managing reverts that cross over to the pre-delete state. So we track pending writes in a stack that can be reverted to at the appropriate time. --- It's important not to accidentally create empty accounts, so don't set empty storage root in a missing account. --- Start reporting a storage root as updated, even if the storage root is identical. Why? In pre-Byzantium, the storage root is reported at each transaction. If one transaction changes the storage and then another changes it back, then we need to treat the storage in the second transaction as changed, even though it's identical to the start root, which is always kept as the root at the beginning of the block.

carver mentioned this pull request Jan 29, 2020

Consensus failure on contract create/destruct within same block (both FrontierVM and PetersburgVM) #1912

Closed

carver commented Jan 29, 2020

View reviewed changes

eth/db/storage.py Outdated Show resolved Hide resolved

carver force-pushed the fix-1912-consensus-bug branch from f4cba85 to 86be04f Compare January 30, 2020 00:40

veox reviewed Jan 30, 2020

View reviewed changes

carver force-pushed the fix-1912-consensus-bug branch from 86be04f to 36b0e5a Compare January 30, 2020 23:00

carver marked this pull request as ready for review January 31, 2020 00:07

veox reviewed Jan 31, 2020

View reviewed changes

eth/db/storage.py Show resolved Hide resolved

veox reviewed Jan 31, 2020

View reviewed changes

eth/db/storage.py Show resolved Hide resolved

carver assigned pipermerriam Jan 31, 2020

carver changed the title ~~Add test that deleted account stays deleted~~ Fix consensus bug from deleting account in same block that creates it Feb 1, 2020

carver mentioned this pull request Feb 1, 2020

Contribute some account storage reset tests to ethereum/tests #1914

Open

veox mentioned this pull request Feb 1, 2020

Consensus failure (full-sync, all chains) on contract create/destruct within same block ethereum/trinity#1478

Closed

pipermerriam approved these changes Feb 6, 2020

View reviewed changes

carver added 5 commits February 10, 2020 11:42

Add tests that deleted account stays deleted

e1c70ad

Ignore a synthetic test (impossible on mainnet)

7764ea8

Log block number when block import fails

64bd3c2

Add release notes for ethereum#1912

14a0785

carver force-pushed the fix-1912-consensus-bug branch from 30ee138 to 14a0785 Compare February 10, 2020 19:46

carver merged commit e3ccf92 into ethereum:master Feb 10, 2020

carver deleted the fix-1912-consensus-bug branch February 10, 2020 19:56

carver mentioned this pull request Feb 10, 2020

Upgrade py-evm to v0.3.0-alpha.14 ethereum/trinity#1544

Merged

2 tasks

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Fix consensus bug from deleting account in same block that creates it #1913

Fix consensus bug from deleting account in same block that creates it #1913

carver commented Jan 29, 2020 •

edited

Loading

carver commented Jan 30, 2020 •

edited

Loading

veox Jan 30, 2020

veox commented Jan 30, 2020

veox commented Jan 30, 2020 •

edited

Loading

pipermerriam commented Jan 30, 2020

carver commented Jan 30, 2020

carver commented Jan 30, 2020

carver commented Jan 30, 2020

carver commented Jan 31, 2020 •

edited

Loading

veox commented Jan 31, 2020 •

edited

Loading

veox commented Jan 31, 2020 •

edited

Loading

carver commented Jan 31, 2020 •

edited

Loading

carver commented Jan 31, 2020

carver commented Jan 31, 2020 •

edited

Loading

carver commented Jan 31, 2020 •

edited

Loading

carver commented Jan 31, 2020 •

edited

Loading

carver commented Feb 1, 2020

cburgdorf commented Feb 1, 2020 via email •

edited

Loading

veox commented Feb 1, 2020

veox commented Feb 1, 2020

pipermerriam left a comment

pipermerriam Feb 6, 2020

pipermerriam Feb 6, 2020

pipermerriam Feb 6, 2020

pipermerriam Feb 6, 2020

carver Feb 10, 2020

Fix consensus bug from deleting account in same block that creates it #1913

Fix consensus bug from deleting account in same block that creates it #1913

Conversation

carver commented Jan 29, 2020 • edited Loading

What was wrong?

How was it fixed?

To-Do

Cute Animal Picture

carver commented Jan 30, 2020 • edited Loading

veox Jan 30, 2020

Choose a reason for hiding this comment

veox commented Jan 30, 2020

veox commented Jan 30, 2020 • edited Loading

pipermerriam commented Jan 30, 2020

carver commented Jan 30, 2020

carver commented Jan 30, 2020

carver commented Jan 30, 2020

carver commented Jan 31, 2020 • edited Loading

veox commented Jan 31, 2020 • edited Loading

veox commented Jan 31, 2020 • edited Loading

carver commented Jan 31, 2020 • edited Loading

carver commented Jan 31, 2020

carver commented Jan 31, 2020 • edited Loading

carver commented Jan 31, 2020 • edited Loading

carver commented Jan 31, 2020 • edited Loading

carver commented Feb 1, 2020

cburgdorf commented Feb 1, 2020 via email • edited Loading

veox commented Feb 1, 2020

veox commented Feb 1, 2020

pipermerriam left a comment

Choose a reason for hiding this comment

pipermerriam Feb 6, 2020

Choose a reason for hiding this comment

pipermerriam Feb 6, 2020

Choose a reason for hiding this comment

pipermerriam Feb 6, 2020

Choose a reason for hiding this comment

pipermerriam Feb 6, 2020

Choose a reason for hiding this comment

carver Feb 10, 2020

Choose a reason for hiding this comment

carver commented Jan 29, 2020 •

edited

Loading

carver commented Jan 30, 2020 •

edited

Loading

veox commented Jan 30, 2020 •

edited

Loading

carver commented Jan 31, 2020 •

edited

Loading

veox commented Jan 31, 2020 •

edited

Loading

veox commented Jan 31, 2020 •

edited

Loading

carver commented Jan 31, 2020 •

edited

Loading

carver commented Jan 31, 2020 •

edited

Loading

carver commented Jan 31, 2020 •

edited

Loading

carver commented Jan 31, 2020 •

edited

Loading

cburgdorf commented Feb 1, 2020 via email •

edited

Loading