py-evm fails to verify the Istanbul fork

[lithp]

• py-evm Version: dd15bb5 (merge-base with master is bc476b2, which is just a few commits behind master)

What is wrong?

The Istanbul block (9069000) fails to validate:

23:54:09.609 DEBUG: BLOCK REWARD: 2000000000000000000 -> b'Z\x0bT\xd5\xdc\x17\xe0\xaa\xdc8=-\xb4;\n\r>\x02\x9cL'
23:54:10.303 WARNING: Failed to validate header proof of work on header: {'parent_hash': b'\x1d\xb3\xfap\xc7\xce\xb9\xee\x9f?\xff)8|r\xd4p\x80\x84:\t\x9b~\xa9\x016\x97\xf5t9S\x8b', 'uncles_hash': b'\x1d\xccM\xe8\xde\xc7]z\xab\x85\xb5g\xb6\xcc\xd4\x1a\xd3\x12E\x1b\x94\x8at\x13\xf0\xa1B\xfd@\xd4\x93G', 'coinbase': b'Z\x0bT\xd5\xdc\x17\xe0\xaa\xdc8=-\xb4;\n\r>\x02\x9cL', 'state_root': b"\xde#q\xed_\xe2L\x90\xda\xaa\x0b\x1a?F\xa4U\xa7\r\xafx\xc0:\xb9\x1f\xd4\xf6\x15\xa1].\xd6'", 'transaction_root': b'\xce\xe1e\x01\xe0\x07\xfeR@\xaaP\xfa\xa9l\xce`\xc7\xde\x8a\xe5o4\x04M\x85\x0e7\x8b\x98\xe0E7', 'receipt_root': b'c\xf2\x1eN\xdc\xd7\xee\xc9\xb2\x16\xe8S\xf4e\x9c\x879\xb5\xa0i&\t\xba\xdc\xeaoa\xcb`\x81J\xfc', 'bloom': 7079330804815871183980463947225265977274564861253117501168643323664475186055883747419352930237005858790595026312524948224582774794563495980117503487312119212598388669452930875830291378422925769306608954621025263688503356533018537326309509600605498870781086873860408243525558461017809631502159078831060259028109833820241268642839335906757268550165683680040815298371119886356874764035130706399255862343530662729121325797577452288762858792050175065308223160799495321271061312380462061572754292461198988970597695365635763000441147961336740392701976668877811898851467744765419121516200699617844299489420880102738564874340, 'difficulty': 2557722798171005, 'block_number': 9069000, 'gas_limit': 8950633, 'gas_used': 8230552, 'timestamp': 1575764709, 'extra_data': b'PPYE sparkpool-eth-tw', 'mix_hash': b'\x8fs\xe0/t\x88\xe2\xe7\xa1\xc0\x9b\xdf\xf0c\xc5\xd48\xf3\x18\x1f\xa0\xbao\xf9\xc2^\x94OS\xc2\x9d\xb3', 'nonce': b'C\xbafp\x02[\xc5\xe0'}
Traceback (most recent call last):
  File "scripts/gethimport.py", line 524, in <module>
    process_blocks(gethdb, chain, args.endblock)
  File "scripts/gethimport.py", line 469, in process_blocks
    imported_block, _, _ = chain.import_block(block, perform_validation = True)
  File "/home/brian/.pyenv/versions/3.7.3/lib/python3.7/site-packages/eth/chains/base.py", line 723, in import_block
    imported_block = self.get_vm(base_header_for_import).import_block(block)
  File "/home/brian/.pyenv/versions/3.7.3/lib/python3.7/site-packages/eth/vm/base.py", line 603, in import_block
    return self.mine_block()
  File "/home/brian/.pyenv/versions/3.7.3/lib/python3.7/site-packages/eth/vm/base.py", line 614, in mine_block
    self.validate_block(final_block)
  File "/home/brian/.pyenv/versions/3.7.3/lib/python3.7/site-packages/eth/vm/base.py", line 860, in validate_block
    self.validate_header(block.header, parent_header)
  File "/home/brian/.pyenv/versions/3.7.3/lib/python3.7/site-packages/eth/vm/base.py", line 932, in validate_header
    cls.validate_seal(header)
  File "/home/brian/.pyenv/versions/3.7.3/lib/python3.7/site-packages/eth/vm/base.py", line 947, in validate_seal
    header.mix_hash, header.nonce, header.difficulty)
  File "/home/brian/.pyenv/versions/3.7.3/lib/python3.7/site-packages/eth/consensus/pow.py", line 83, in check_pow
    encode_hex(keccak(cache)),
eth_utils.exceptions.ValidationError: mix hash mismatch; expected: 0x49f69c616365ee5063670e4170357be09a904b260949a673dfd02ba72653def7 != actual: 0x8f73e02f7488e2e7a1c09bdff063c5d438f3181fa0ba6ff9c25e944f53c29db3. Mix hash calculated from block #9069000, mine hash 0xcc16425c8a7839c7bd7b31ffd85e143f2edaf66e11768a82791e66e9937a09e2, nonce 0x43ba6670025bc5e0, difficulty 2557722798171005, cache hash 0x7d8dc56dffec0be00bce2d28be6870072eeb8ea18a39c3044e358f896c4911b3

[lithp]

When I disable the validate_seal check I get closer to the real problem:

Traceback (most recent call last):
  File "scripts/gethimport.py", line 524, in <module>
    process_blocks(gethdb, chain, args.endblock)
  File "scripts/gethimport.py", line 469, in process_blocks
    imported_block, _, _ = chain.import_block(block, perform_validation = True)
  File "/home/brian/py-evm/eth/chains/base.py", line 431, in import_block
    validate_imported_block_unchanged(imported_block, block)
  File "cytoolz/functoolz.pyx", line 250, in cytoolz.functoolz.curry.__call__
  File "/home/brian/py-evm/eth/_utils/rlp.py", line 89, in validate_rlp_equal
    raise ValidationError(error_message)
eth_utils.exceptions.ValidationError: Mismatch between block and imported block on 3 fields:
 - header.state_root  :
    (actual)  : b'qXS\xcb\x85\x92\xc7\x18\xf0,\x07\xbe\xc5\xb0\xf2\x88>J\xb9\x00\xe8#G\xac\x07U\xc9YjN\xbc\xf1'                                                                                                   
    (expected): b'\xf3\x91y\x14\xf6\x93\xa9\x85\xa2>\xe2\xb6#\xf6\xd1\xc1\xbc\xff\xb8\xe5\x97\xe6<\xf1\xfb\x0c\xba\xbb\x99G\xa9\xc7'                                                                              
 - header.receipt_root:
    (actual)  : b'\xbaj\xca\xe5\xe3\xea3\x8e\xff\xbe\xd4\x85\xc6\x97\xb2\xe0A\x86\xa1\x03H/\xd6_\x17\xdf\x81\xee\n8\x19\xe4'                                                                                      
    (expected): b'E\xe8\x9a\xb9\x9b\xa6W?][_\x97\x1a\x19\xba\xa3g\xb5W\xc5\x04\xc3K\xb2\xa9\xfe\xf3z\\\x88\xecq'                                                                                                  
 - header.gas_used    :
    (actual)  : 8632735
    (expected): 8762935

[lithp]

The first incorrect transaction is this one. Geth says it consumed 251476 gas, but py-evm says 238876 gas.

[lithp]

I wanted to figure out what was happening tonight but it looks like geth is going to take another 50 minutes to finish generating a trace, off to bed for now.

[carver]

Looks like a bug in looking up the "original value": py-evm is using the journalled value from the beginning of the block (or really, since the last time we made the state root). 🪲

[lithp]

After spending time quality time comparing traces I found the first place gas costs diverge. There was an SSTORE geth was charging 5000 gas for but which Trinity only charged 800 gas. Jason realized this was happening because Trinity does the wrong thing in the case where a storage item is being changed for the first time in a transaction but for a subsequent time in the current block.

The relevant Istanbul EIP: https://eips.ethereum.org/EIPS/eip-2200

[pipermerriam]

Lets be sure to generate a fixture test that would have caught this and contribute it back upstream.