Vyper: Cannot post events after create an uninitialized local variable

Created on 11 Jun 2019  路  32Comments  路  Source: vyperlang/vyper

When working with the Eth2 deposit contract I noticed a strange behaviour which I presume is a compiler bug.

Notice that the tests pass in https://github.com/ethereum/eth2.0-specs/pull/1152/commits/abe48cc98857c3350d45656d3d4a6f2e6af2784d (the command to run the tests is make compile_deposit_contract; make test_deposit_contract) but fail if you move line 92 (the Deposit log) to line 80 the tests fail when nothing has really changed. I haven't had time to debug it but my guess would be that that it has something to do with zero_bytes32: bytes32, possibly that junk is being written to it.

bug

Most helpful comment

There might be something else going on here too because I'm not sure the frame of the private function in this issue is that large to overwrite callee memory. But I did notice that the newly declared variable is not zeroed in the IR as I mentioned above, and the fact that explicitly setting the new variable fixes the issue is pretty telling.

All 32 comments

To prove that theory, could you move line 92 to just before line 80, and modify line 80 to be zero_bytes21: bytes32 = 0x0000....0000, and see if you get the same issue?

It does indeed seem strange to be encountering this behavior

What's the syntax again? I tried zero_bytes32: bytes32 = 0x00, zero_bytes32: bytes32 = 0, zero_bytes32: bytes32 = bytes32(0)鈥攁ll fail.

You either have to type out all the zeros, use convert(0, bytes32), or simply use EMPTY_BYTES32. All should work.

Yep, when explicitly setting zero_bytes32: bytes32 = convert(0, bytes32) it works. Definitely compiler bug.

Not sure why this creates exceptional behavior, but I agree it definitely shouldn't be doing that.

@JustinDrake

I'm having trouble reproducing this failure. I checked out https://github.com/ethereum/eth2.0-specs/commit/abe48cc98857c3350d45656d3d4a6f2e6af2784d , moved line 92 to be line 80 (put it just before the uninitialized zero_bytes32 variable declaration), and the functional tests are passing for me:
Screen Shot 2019-06-12 at 1 47 38 PM

The failure is because the ABIs don't match due to the gas estimates being different. That in itself is weird and I'm trying to understand what's going on there, but is that related to the issues you were having? My guess is not.

@JustinDrake Do you have a link to a failing build job or something that would make it a bit clearer how things are failing for you?

@davesque Can you also show the output of make compile_deposit_contract (which should be run before make test_deposit_contract).

@JustinDrake

Alright, here's what I'm getting. And I'm guessing this is the error you're seeing:

(venv) Davids-MacBook-Pro-2 ~/projects/eth2.0-specs
$ make compile_deposit_contract
Makefile:101: warning: overriding commands for target `eth2.0-spec-tests/tests'
Makefile:98: warning: ignoring old commands for target `eth2.0-spec-tests/tests'
cd ./deposit_contract; . venv/bin/activate; \
        python tool/compile_deposit_contract.py contracts/validator_registration.v.py;
(venv) Davids-MacBook-Pro-2 ~/projects/eth2.0-specs
$ make test_deposit_contract
Makefile:101: warning: overriding commands for target `eth2.0-spec-tests/tests'
Makefile:98: warning: ignoring old commands for target `eth2.0-spec-tests/tests'
cd ./deposit_contract; . venv/bin/activate; \
        python -m pytest .
============================================================================================================ test session starts =============================================================================================================
platform darwin -- Python 3.6.8, pytest-3.6.1, py-1.8.0, pluggy-0.6.0
rootdir: /Users/david/projects/eth2.0-specs/deposit_contract, inifile:
collected 11 items

tests/contracts/test_compile.py .                                                                                                                                                                                                      [  9%]
tests/contracts/test_deposit.py .........F                                                                                                                                                                                             [100%]

================================================================================================================== FAILURES ==================================================================================================================
_____________________________________________________________________________________________________________ test_deposit_tree ______________________________________________________________________________________________________________

registration_contract = <web3._utils.datatypes.Contract object at 0x10885e6d8>, w3 = <web3.main.Web3 object at 0x10880f9e8>, assert_tx_failed = <function assert_tx_failed.<locals>.assert_tx_failed at 0x10870cbf8>
deposit_input = (b'\x11\x11\x11\x11\x11\x11\x11\x11\x11\x11\x11\x11\x11\x11\x11\x11\x11\x11\x11\x11\x11\x11\x11\x11\x11\x11\x11\x11\x1...""""""""""""""""', b'333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333333')

    def test_deposit_tree(registration_contract, w3, assert_tx_failed, deposit_input):
        log_filter = registration_contract.events.Deposit.createFilter(
            fromBlock='latest',
        )

        deposit_amount_list = [randint(MIN_DEPOSIT_AMOUNT, FULL_DEPOSIT_AMOUNT * 2) for _ in range(10)]
        leaf_nodes = []
        for i in range(0, 10):
            tx_hash = registration_contract.functions.deposit(
                *deposit_input,
            ).transact({"value": deposit_amount_list[i] * eth_utils.denoms.gwei})
            receipt = w3.eth.getTransactionReceipt(tx_hash)
            print("deposit transaction consumes %d gas" % receipt['gasUsed'])

            logs = log_filter.get_new_entries()
            assert len(logs) == 1
            log = logs[0]['args']

            assert log["index"] == i.to_bytes(8, 'little')

            deposit_data = DepositData(
                pubkey=deposit_input[0],
                withdrawal_credentials=deposit_input[1],
                amount=deposit_amount_list[i],
                signature=deposit_input[2],
            )
            hash_tree_root_result = hash_tree_root(deposit_data)
            leaf_nodes.append(hash_tree_root_result)
            root = compute_merkle_root(leaf_nodes)
>           assert root == registration_contract.functions.get_deposit_root().call()
E           AssertionError: assert b'f\xa3=\x90\...4\xb6\xe6\x10' == b'n\xaa\xe6\x8...f-Zz\x14\xd2+'
E             At index 0 diff: 102 != 110
E             Use -v to get the full diff

tests/contracts/test_deposit.py:163: AssertionError
------------------------------------------------------------------------------------------------------------ Captured stdout call ------------------------------------------------------------------------------------------------------------
deposit transaction consumes 122642 gas
==================================================================================================== 1 failed, 10 passed in 20.15 seconds ====================================================================================================
make: *** [test_deposit_contract] Error 1
(venv) Davids-MacBook-Pro-2 ~/projects/eth2.0-specs
$

Yep, that's the error! :) (Note that the error changes every time because there is some randomisation.)

@JustinDrake Yeah, I did notice that. Thanks for the help.

@JustinDrake does https://github.com/ethereum/vyper/pull/1484 fix the issue for you?

but also, uninitialized variables are not guaranteed to refer to zeroed memory. so maybe we should disallow declaring variables without initializing them.

so maybe we should disallow declaring variables without initializing them.

:+1: this

Or always set new variables to 0. I'm open to either TBH - let's discuss at next meeting?

Agreed, but forcing the user to set is more explicit and clear and avoids this condition entirely.

Could optimize out the write if it is provable that no read occurs before write.

So uninitialised variables are not guaranteed for now to have default initial values as the documentation seems to suggest here: https://vyper.readthedocs.io/en/latest/types.html#initial-values?

Yeah, it seems that was an oversight.

@charles-cooper this feels like a bug, when is memory not zeroed/initialised ?

I think after a call to a private function as you suspected in https://github.com/ethereum/vyper/issues/1493#issuecomment-505556220. There could be something else going on but I inspected the IR and didn't see set to 0 for new variables that are declared after return from private.

Yip we should fix that, for Basetypes it should be relatively easy. Dynamic types will be slightly more work, as we need zero the whole range.

It doesn't seem like this is the right answer then. Shouldn't whatever solution we come up with avoid the need to set dynamic types, which will be needlessly expensive?

It's quite of an edge case that I don't think it should be too much of a problem, defining large dynamic types in the EVM will always be costly.

@jacqueswww I'm trying to remember if the zero by default behavior applies to the EVM memory in addition to the storage. If that were the case, wouldn't uninitialized variables already be zeroed assuming the memory counter is incremented to accommodate them? I'm poking through the spec right now trying to see if this is the case. I'm also a bit out of context here so feel free to correct me.

Actually, yeah here's where I saw that in the "Execution Model" section of the yellow paper:
Screen Shot 2019-06-25 at 3 12 35 PM

Are memory positions re-used across the execution of a method call? If so, then I can understand the trouble.

@davesque Yes that is true, but this occurs after a local call was made - which re-uses the same memory.
Hence it's an edge case, best handled by the compiler IMHO.

@davesque just looking at the exception above further,

@public
@constant
def get_deposit_root() -> bytes32:
    node: bytes32 = 0x0000000000000000000000000000000000000000000000000000000000000000
    size: uint256 = self.deposit_count
    for height in range(DEPOSIT_CONTRACT_TREE_DEPTH):
        if bitwise_and(size, 1) == 1:  # More gas efficient than `size % 2 == 1`
            node = sha256(concat(self.branch[height], node))
        else:
            node = sha256(concat(node, self.zero_hashes[height]))
        size /= 2
    return node

This is the function that fails? Or is this the fixed code?

@jacqueswww Yeah, it's a bit confusing to reproduce. I made a fork with a commit that shows the failure. Here's how you can access it:

git clone https://github.com/davesque/eth2.0-specs/
cd eth2.0-specs
git checkout with-failure
make install_deposit_contract_test
make compile_deposit_contract
make test_deposit_contract

The with-failure tag is on a commit that makes the change that produces the failure. The without-failure tag is the commit just before that which doesn't produce the failure.

@jacqueswww Here's the actual commit that causes the failure: https://github.com/davesque/eth2.0-specs/commit/1c2858f9068a228845617e9965d812adb5235680

I think many of the people involved in this discussion are already aware of this, but for posterity here's a comment I just posted with more information about what I think is happening here: https://github.com/ethereum/vyper/issues/1493#issuecomment-507424856

There might be something else going on here too because I'm not sure the frame of the private function in this issue is that large to overwrite callee memory. But I did notice that the newly declared variable is not zeroed in the IR as I mentioned above, and the fact that explicitly setting the new variable fixes the issue is pretty telling.

Was this page helpful?
0 / 5 - 0 ratings