search

trufflesuite / ganache

:warning: The Truffle Suite is being sunset. For information on ongoing support, migration options and FAQs, visit the Consensys blog. Thank you for all the support over the years.
https://consensys.io/blog/consensys-announces-the-sunset-of-truffle-and-ganache-and-new-hardhat?utm_source=github&utm_medium=referral&utm_campaign=2023_Sep_truffle-sunset-2023_announcement_
MIT License
2.62k stars 682 forks source link

Transaction status is 1, but last opcode is REVERT #611

Closed BlinkyStitt closed 4 years ago

BlinkyStitt commented 4 years ago

I have a project that uses brownie and ganache-cli --fork against a geth node. (Geth is running according to these steps).

A few of my tests check the return_value of my transactions. Most succeed, but one has no return value despite not reverting.

Expected Behavior

A transaction with a status of 1 should have a return value.

Current Behavior

Steps to Reproduce

  1. git clone https://github.com/SatoshiAndKin/argobytes-contracts-brownie (at ecf07c4)
  2. Follow the readme
  3. ./scripts/test.sh tests/test_uniswap_v1_arbitrage.py -I
./scripts/test.sh tests/test_uniswap_v1_arbitrage.py -I
+ [ -z /home/ski/code/argobytes-contracts-brownie/venv ]
+ brownie test --network mainnet-fork tests/test_uniswap_v1_arbitrage.py -I
Brownie v1.8.9 - Python development framework for Ethereum

===================================================================================== test session starts =====================================================================================
platform linux -- Python 3.8.2, pytest-5.4.2, py-1.8.1, pluggy-0.13.1
rootdir: /home/ski/code/argobytes-contracts-brownie
plugins: eth-brownie-1.8.9, forked-1.1.3, web3-5.10.0, hypothesis-5.15.0, xdist-1.32.0
collecting ... Attached to local RPC client listening at '127.0.0.1:8575'...
collected 1 item                                                                                                                                                                              

tests/test_uniswap_v1_arbitrage.py F
address_zero = '0x0000000000000000000000000000000000000000', argobytes_atomic_trade = <ArgobytesAtomicTrade Contract '0xF024fE5EF0b1Bf88caf9B1222E49d1A5CC312a71'>
dai_erc20 = <Dai Contract '0x6B175474E89094C44Da98b954EedeAC495271d0F'>, argobytes_owned_vault = <ArgobytesOwnedVault Contract '0xb66F46436fa703237A9Fd26f4DA63919D3cc943D'>
example_action = <ExampleAction Contract '0xDb43EFA90874d427e38Ff1e5F08572c0a2619930'>, chi = <ChiToken Contract '0x0000000000004946c0e9F43F4Dee607b0eF1fA1c'>
uniswap_v1_factory = <Vyper_contract Contract '0xc0a47dFe034B400B47bDaD5FecDa2621de6c4d95'>, uniswap_v1_action = <UniswapV1Action Contract '0x006ba56B025c63aE46c510a904422945F2389d6F'>
usdc_erc20 = <FiatTokenProxy Contract '0xA0b86991c6218b36c1d19D4a2e9Eb0cE3606eB48'>

    def test_uniswap_arbitrage(address_zero, argobytes_atomic_trade, dai_erc20, argobytes_owned_vault, example_action, chi, uniswap_v1_factory, uniswap_v1_action, usdc_erc20):
        assert argobytes_owned_vault.balance() == 0
        assert example_action.balance() == 0

        value = 1e18

        # send some ETH into the vault
        accounts[0].transfer(argobytes_owned_vault, value)
        # send some ETH into the sweep contract to simulate arbitrage profits
        accounts[0].transfer(example_action, value)

        # mint some gas token
        # TODO: how much should we make?
        argobytes_owned_vault.mintGasToken(chi, 26, {"from": accounts[0]})

        # make sure balances match what we expect
        assert argobytes_owned_vault.balance() == value
        assert example_action.balance() == value

        usdc_exchange = uniswap_v1_action.getExchange(uniswap_v1_factory, usdc_erc20)
        dai_exchange = uniswap_v1_action.getExchange(uniswap_v1_factory, dai_erc20)

        # sweep a bunch of times to use up gas
        encoded_actions = argobytes_atomic_trade.encodeActions(
            [
                example_action,
                uniswap_v1_action,
                uniswap_v1_action,
                uniswap_v1_action,
            ],
            [
                # add some faked profits
                example_action.sweep.encode_input(uniswap_v1_action, address_zero),

                # trade ETH to USDC
                # uniswap_v1_action.tradeEtherToToken(address to, address exchange, address dest_token, uint dest_min_tokens, uint trade_gas)
                uniswap_v1_action.tradeEtherToToken.encode_input(uniswap_v1_action, usdc_exchange, usdc_erc20, 1, 0),

                # trade USDC to DAI
                # uniswap_v1_action.tradeTokenToToken(address to, address exchange, address src_token, address dest_token, uint dest_min_tokens, uint trade_gas)
                uniswap_v1_action.tradeTokenToToken.encode_input(
                    uniswap_v1_action, usdc_exchange, usdc_erc20, dai_erc20, 1, 0),

                # trade DAI to ETH
                # uniswap_v1_action.tradeTokenToEther(address to, address exchange, address src_token, uint dest_min_tokens, uint trade_gas)
                uniswap_v1_action.tradeTokenToEther.encode_input(address_zero, dai_exchange, dai_erc20, 1, 0),
            ],
        )

        arbitrage_tx = argobytes_owned_vault.atomicArbitrage(
            chi, argobytes_atomic_trade, address_zero, [address_zero], value, encoded_actions, {'from': accounts[1]})

        assert argobytes_owned_vault.balance() > value

        # make sure the transaction succeeded
        # there should be a revert above if status == 0, but something is wrong
        assert arbitrage_tx.status == 1
>       assert arbitrage_tx.return_value is not None
E       AssertionError: assert None is not None
E        +  where None = <Transaction '0x903f37e1596487075620d2c83dea892287b553c0147d97fb8bf4642a2083e177'>.return_value

tests/test_uniswap_v1_arbitrage.py:67: AssertionError

Interactive mode enabled. Use quit() to continue running tests.
>>> arbitrage_tx.trace[-1]['op']                                                                                                                                                               
'REVERT'
>>> arbitrage_tx._trace[-1]['op']                                                                                                                                                              
'REVERT'
>>>

Context

Due to previous issues with reverting traces pointing to incorrect lines, I've disabled solc's runs, so that shouldn't be the problem.

I suspected that gastoken2/chi might be related to the issue, but removing that code didn't change anything.

I'm sure the transaction isn't actually reverting because my test balance increases after the transaction is completed. If the transaction had reverted, the balance would not increase.

I don't think Brownie is the problem here. Brownie just gets the trace from ganache.

Your Environment

BlinkyStitt commented 4 years ago

I noticed that the call_trace is shorter than I expect:

>>> arbitrage_tx.call_trace()                                                                                                                                                                  
Call trace for '0x396df1e2e96ac4779df1dd6379c3684fc952f8a3e104d75aee048d1f2ea0b057':
ArgobytesOwnedVault.atomicArbitrage 0:12892  (0x0F8B800bb499Be1A538D5d18556163C1C42a83E0)
├─GasTokenBurner.startFreeGasTokens 470:491
├─AccessControl.hasRole 562:647
│ └─EnumerableSet.contains 589:639
│   └─EnumerableSet._contains 602:631
├─UniversalERC20.universalBalanceOf 787:830
│ └─UniversalERC20.isETH 793:812
├─UniversalERC20.universalTransfer 852:1004
│ ├─UniversalERC20.isETH 865:884
│ └─ArgobytesAtomicTrade 956:969  (0x59D67dC8DF1C4d1ef77787b1a95954C9465d4A14)
├─ArgobytesAtomicTrade.atomicTrade 1490:11507  (0x59D67dC8DF1C4d1ef77787b1a95954C9465d4A14)
│ ├─UniversalERC20.universalBalanceOf 1943:1986
│ │ └─UniversalERC20.isETH 1949:1968
│ ├─ArgobytesAtomicTrade.executeSolo 2163:11507
│ │ ├─UniversalERC20.universalBalanceOf 4095:4138
│ │ │ └─UniversalERC20.isETH 4101:4120
│ │ ├─UniversalERC20.universalTransfer 4179:4331
│ │ │ ├─UniversalERC20.isETH 4192:4211
│ │ │ └─ExampleAction 4283:4296  (0x5408F18ac36973Ed918edE34D8889d590f0aC537)
│ │ ├─ExampleAction.sweep 4585:5046  (0x5408F18ac36973Ed918edE34D8889d590f0aC537)
│ │ │ ├─UniversalERC20.universalBalanceOf 4814:4857
│ │ │ │ └─UniversalERC20.isETH 4820:4839
│ │ │ └─UniversalERC20.universalTransfer 4885:5037
│ │ │   ├─UniversalERC20.isETH 4898:4917
│ │ │   └─UniswapV1Action 4989:5002  (0xEAD0eA5a65D23E271097695c5A01BAF047496609)
│ │ ├─UniswapV1Action.tradeEtherToToken 5396:7430  (0xEAD0eA5a65D23E271097695c5A01BAF047496609)
│ │ │ └─<UnknownContract>.0xad65d76d 5973:7418  (0x97deC872013f6B5fB443861090ad931542878126)
│ │ │   └─<UnknownContract>.0xad65d76d 5984:7415  (0x2157A7894439191e520825fe9399aB8655E0f708)
│ │ │     ├─FiatTokenProxy.balanceOf 6186:6495  (0xA0b86991c6218b36c1d19D4a2e9Eb0cE3606eB48)
│ │ │     │ ├─Proxy._fallback 6230:6495
│ │ │     │ │ ├─AdminUpgradeabilityProxy._willFallback 6234:6273
│ │ │     │ │ │ ├─AdminUpgradeabilityProxy._admin 6238:6253
│ │ │     │ │ │ └─Proxy._willFallback 6269:6271
│ │ │     │ │ ├─UpgradeabilityProxy._implementation 6278:6293
│ │ │     │ │ ├─Proxy._delegate 6296:6495
│ │ │     │ │ │ └─FiatTokenV1.balanceOf 6308:6482  (0x0882477e7895bdC5cea7cB1552ed914aB157Fe56)
│ │ │     └─FiatTokenProxy.transfer 6822:7410  (0xA0b86991c6218b36c1d19D4a2e9Eb0cE3606eB48)
│ │ │       └─Proxy._fallback 6866:7410
│ │ │         ├─AdminUpgradeabilityProxy._willFallback 6870:6909
│ │ │         │ ├─AdminUpgradeabilityProxy._admin 6874:6889
│ │ │         │ └─Proxy._willFallback 6905:6907
│ │ │         ├─UpgradeabilityProxy._implementation 6914:6929
│ │ │         └─Proxy._delegate 6932:7410
│ │ │           └─FiatTokenV1.transfer 6944:7396  (0x0882477e7895bdC5cea7cB1552ed914aB157Fe56)
│ │ │             ├─SafeMath.sub 7278:7299
│ │ │             └─SafeMath.add 7350:7374
│ │ ├─Strings.toString 7458:7643
│ │ └─Strings2.toString 7650:10726
├─GasTokenBurner.endFreeGasTokens 11653:11731
│ └─SafeMath.sub 11671:11723
└─GasTokenBurner._freeGasTokens 11739:12644
  └─ChiToken.freeUpTo 11870:12535  (0x0000000000004946c0e9F43F4Dee607b0eF1fA1c)
    ├─ERC20WithoutTotalSupply.balanceOf 11946:11967
    ├─Math.min 11970:11984
    └─ChiToken.free 11987:12513
      ├─ERC20WithoutTotalSupply._burn 11994:12103
      │ └─SafeMath.sub 12039:12056
      └─ChiToken._destroyChildren 12108:12509
        ├─ChiToken.computeAddress2 12125:12190
        ├─<UnknownContract>.0x00000000 12211:12218  (0xdB392efce2Cf6AdE5505A2Cb2B438Df1F0c983b4)
        ├─ChiToken.computeAddress2 12253:12318
        ├─<UnknownContract>.0x00000000 12339:12346  (0x03162B21b8D7F054584A2882d4CC653DD22c1c84)
        ├─ChiToken.computeAddress2 12381:12446
        └─<UnknownContract>.0x00 12467:12474  (0x6975B3E13bbc6A26b8A74db1C49A2e306d4E9D84)
>>>

It ends with ChiToken, like I expect, but there should be more calls to UniswapV1Action in the call_trace. Right now it is only showing tradeEtherToToken, but there should also be tradeTokenToToken and tradeTokenToEth. I'm sure these are being called, otherwise the test wouldn't see an increase in balance at the end.

BlinkyStitt commented 4 years ago

So I copied this test and changed it to work for kyber. And the kyber test had the correct return_value set! So I think maybe uniswap using vyper might be related.

BlinkyStitt commented 4 years ago

If I skip the gas token burning and shorten the amount of calls, it gives a return_value. So I think this is related to some complexities in freeing GST2/CHI

BlinkyStitt commented 4 years ago

Should I open this on ganache-core instead?

mikeseese commented 4 years ago

@WyseNynja I was able to use Github's transfer function to move this to ganache-core as we do try to keep core functionality separate from the CLI repo. (I think we're thinking of a monorepo to simplify all of this in the future)

mikeseese commented 4 years ago

@WyseNynja I'm having issues with just running your setup. When I finally run the test command you provided, I get: 

tests/test_uniswap_v1_arbitrage.py E
    @pytest.fixture(scope="session")
    def dai_erc20():
>       yield Contract.from_explorer("0x6b175474e89094c44da98b954eedeac495271d0f")
E       ValueError: Explorer API not set for this network

tests/conftest.py:80: ValueError

The only thing I changed was brownie-network-config.yaml@38 I changed the fork: mainnet to fork: https://mainnet.infura.io/v3/<my-infura-key>

here's my bash history:

nvm use 12
./scripts/setup.sh 
./venv/bin/brownie networks import brownie-network-config.yaml True
. ./scripts/activate
brownie compile
npm i -g ganache-cli
BURN_GAS_TOKEN=0 ./scripts/test-deploy.sh
./scripts/test.sh tests/test_uniswap_v1_arbitrage.py -I

was i supposed to run both BURN_GAS_TOKEN=1 ... and BURN_GAS_TOKEN=0 ...?

BlinkyStitt commented 4 years ago

I think you want to leave it as fork: mainnet and change the actual mainnet block to use your infura key. (This line: https://github.com/SatoshiAndKin/argobytes-contracts-brownie/blob/master/brownie-network-config.yaml#L13)

Since you've already run brownie networks import, you can edit ~/.brownie/network-config.yaml directly.

BURN_GAS_TOKEN just enables or disable the gas token minting/freeing. It shouldn't change this error.

BlinkyStitt commented 4 years ago

I upgraded brownie and all the other dependencies and also upgraded to ganache-cli 6.10.2-forking.0.

I've changed things around and am using LGT instead of GST2 now, but that hasn't changed the issue.

The test trades ether to token, a token to another token, and that token back to ether. The transaction's status claims success and there is no revert reason, but the call_trace only includes the first trade (ether to token).

$ ./scripts/test.sh tests/test_uniswap_v1_arbitrage.py -I
+ [ -z /home/ski/code/argobytes-contracts-brownie/venv ]
+ brownie test --network mainnet-fork tests/test_uniswap_v1_arbitrage.py -I
Brownie v1.10.6 - Python development framework for Ethereum

============================= test session starts ==============================
platform linux -- Python 3.8.2, pytest-5.4.3, py-1.9.0, pluggy-0.13.1
Test order randomisation NOT enabled. Enable with --random-order or --random-order-bucket=<bucket_type>
rootdir: /home/ski/code/argobytes-contracts-brownie
plugins: eth-brownie-1.10.6, web3-5.11.1, hypothesis-5.26.0, timeout-1.4.2, random-order-1.0.4, xdist-1.34.0, forked-1.3.0
collecting ... 
Launching 'ganache-cli --accounts 10 --hardfork istanbul --fork ws://127.0.0.1:8546 --gasLimit 12000000 --mnemonic opinion adapt negative bone suit ill fossil alcohol razor script damp fold --port 8575'...
collected 1 item                                                                                                                                                                      

tests/test_uniswap_v1_arbitrage.py F
address_zero = '0x0000000000000000000000000000000000000000', argobytes_atomic_trade = <ArgobytesAtomicActions Contract '0x7d182cE21DF6bde1EEf913D04c7f688B351c2F52'>
argobytes_owned_vault = <ArgobytesOwnedVault Contract '0x0F00F5Af520ebD3255141f24aDd53D34A4D9955C'>
uniswap_v1_factory = <Vyper_contract Contract '0xc0a47dFe034B400B47bDaD5FecDa2621de6c4d95'>
uniswap_v1_action = <UniswapV1Action Contract '0x045661743647a37b4606D754A66D1BE95c6Fc6d6'>, usdc_erc20 = <FiatTokenProxy Contract '0xA0b86991c6218b36c1d19D4a2e9Eb0cE3606eB48'>
weth9_erc20 = <WETH9 Contract '0xC02aaA39b223FE8D0A0e5C4F27eAD9083C756Cc2'>

    def test_uniswap_arbitrage(address_zero, argobytes_atomic_trade, argobytes_owned_vault, uniswap_v1_factory, uniswap_v1_action, usdc_erc20, weth9_erc20):
        assert argobytes_owned_vault.balance() == 0
        assert uniswap_v1_action.balance() == 0

        value = 1e18

        # send some ETH into the vault
        accounts[0].transfer(argobytes_owned_vault, value)
        # send some ETH into the action to simulate arbitrage profits
        accounts[0].transfer(uniswap_v1_action, value)

        # make sure balances match what we expect
        assert argobytes_owned_vault.balance() == value
        assert uniswap_v1_action.balance() == value

        usdc_exchange = uniswap_v1_action.getExchange(uniswap_v1_factory, usdc_erc20)
        weth9_exchange = uniswap_v1_action.getExchange(uniswap_v1_factory, weth9_erc20)

        encoded_actions = argobytes_atomic_trade.encodeActions(
            [
                uniswap_v1_action,
                uniswap_v1_action,
                uniswap_v1_action,
            ],
            [
                # trade ETH to USDC
                # uniswap_v1_action.tradeEtherToToken(address to, address exchange, address dest_token, uint dest_min_tokens, uint trade_gas)
                uniswap_v1_action.tradeEtherToToken.encode_input(uniswap_v1_action, usdc_exchange, usdc_erc20, 1, 0),

                # trade USDC to WETH9
                # uniswap_v1_action.tradeTokenToToken(address to, address exchange, address src_token, address dest_token, uint dest_min_tokens, uint trade_gas)
                uniswap_v1_action.tradeTokenToToken.encode_input(
                    uniswap_v1_action, usdc_exchange, usdc_erc20, weth9_erc20, 1, 0),

                # trade WETH9 to ETH
                # uniswap_v1_action.tradeTokenToEther(address to, address exchange, address src_token, uint dest_min_tokens, uint trade_gas)
                uniswap_v1_action.tradeTokenToEther.encode_input(address_zero, weth9_exchange, weth9_erc20, 1, 0),
            ],
            [True, False, False],
        )

        arbitrage_tx = argobytes_owned_vault.atomicArbitrage(
            address_zero, argobytes_atomic_trade, address_zero, [address_zero], value, encoded_actions, {'from': accounts[1]})

        assert argobytes_owned_vault.balance() > value

        # TODO: https://github.com/trufflesuite/ganache-core/issues/611
        # make sure the transaction succeeded
        # there should be a revert above if status == 0, but something is wrong
        assert arbitrage_tx.status == 1
>       assert arbitrage_tx.return_value is not None
E       AssertionError: assert None is not None
E        +  where None = <Transaction '0x813a1336c56100c78f36915bcf9f9ef38c5f5832ec5fa2513caad43893d02e0a'>.return_value

tests/test_uniswap_v1_arbitrage.py:63: AssertionError

Interactive mode enabled. Use quit() to continue running tests.
>>> arbitrage_tx.call_trace()                                                                                                                                                          
Call trace for '0x813a1336c56100c78f36915bcf9f9ef38c5f5832ec5fa2513caad43893d02e0a':
Initial call cost  [141812 gas]
ArgobytesOwnedVault.atomicArbitrage  0:6950  [6146 / 94397 gas]
├── LiquidGasTokenUser.initialGas  468:490  [77 gas]
├── AccessControl.hasRole  561:646  [147 / 1136 gas]
│   └── EnumerableSet.contains  588:638  [66 / 989 gas]
│       └── EnumerableSet._contains  601:630  [923 gas]
├── UniversalERC20.universalBalanceOf  786:829  [782 / 845 gas]
│   └── UniversalERC20.isETH  792:811  [63 gas]
├── UniversalERC20.universalTransfer  854:1026  [126 / 7968 gas]
│   ├── UniversalERC20.isETH  867:886  [63 gas]
│   └── Address.sendValue  895:1012  [324 / 7779 gas]
│       └── ArgobytesAtomicActions  [CALL]  971:984  [7455 gas]
├── ArgobytesAtomicActions.atomicTrades  [CALL]  1509:6550  [189816 / 78185 gas]
│   ├── UniversalERC20.universalBalanceOf  1965:2008  [782 / 845 gas]
│   │   └── UniversalERC20.isETH  1971:1990  [63 gas]
│   └── ArgobytesAtomicActions._executeSolo  2185:6550  [6152 / -112476 gas]
│       └── Address.functionCallWithValue  4011:6550  [58 / -118628 gas]
│           └── Address._functionCallWithValue  4027:6550  [-185663 / -118686 gas]
│               ├── Address.isContract  4033:4070  [809 gas]
│               └── UniswapV1Action.tradeEtherToToken  [CALL]  4332:6489  [10468 / 66168 gas]
│                   └── <UnknownContract>.0xad65d76d  [CALL]  4896:6341  [9052 / 55700 gas]
│                       └── <UnknownContract>.0xad65d76d  [DELEGATECALL]  4907:6338  [10548 / 46648 gas]
│                           ├── FiatTokenProxy.balanceOf  [STATICCALL]  5109:5418  [1550 / 4984 gas]
│                           │   └── Proxy._fallback  5153:5418  [45 / 3434 gas]
│                           │       ├── AdminUpgradeabilityProxy._willFallback  5157:5196  [79 / 932 gas]
│                           │       │   ├── AdminUpgradeabilityProxy._admin  5161:5176  [844 gas]
│                           │       │   └── Proxy._willFallback  5192:5194  [9 gas]
│                           │       ├── UpgradeabilityProxy._implementation  5201:5216  [844 gas]
│                           │       └── Proxy._delegate  5219:5418  [-576 / 1613 gas]
│                           │           └── FiatTokenV1.balanceOf  [DELEGATECALL]  5231:5405  [2189 gas]
│                           └── FiatTokenProxy.transfer  [CALL]  5745:6333  [1384 / 31116 gas]
│                               └── Proxy._fallback  5789:6333  [45 / 29732 gas]
│                                   ├── AdminUpgradeabilityProxy._willFallback  5793:5832  [79 / 932 gas]
│                                   │   ├── AdminUpgradeabilityProxy._admin  5797:5812  [844 gas]
│                                   │   └── Proxy._willFallback  5828:5830  [9 gas]
│                                   ├── UpgradeabilityProxy._implementation  5837:5852  [844 gas]
│                                   └── Proxy._delegate  5855:6333  [-409 / 27911 gas]
│                                       └── FiatTokenV1.transfer  [DELEGATECALL]  5867:6319  [28176 / 28320 gas]
│                                           ├── SafeMath.sub  6201:6222  [68 gas]
│                                           └── SafeMath.add  6273:6297  [76 gas]
└── LiquidGasTokenUser.freeGasTokens  6696:6708  [40 gas]
>>>
mikeseese commented 4 years ago

@WyseNynja I'm trying to run the tests on a separate process of ganache so I can debug it and monitor logs. I created a new live network, but i get the below error:

tests/test_uniswap_v1_arbitrage.py E
self = <brownie.test.fixtures.PytestBrownieFixtures object at 0x7fdb46e3a070>

    @pytest.fixture(scope="module")
    def module_isolation(self):
        """
        Resets the test environment before and after a test module runs. This ensures
        a clean environment for the module, and that it's results will not affect
        subsequent tests.
        """
>       brownie.rpc.reset()
E       SystemError: RPC is not active.

venv/lib/python3.8/site-packages/brownie/test/fixtures.py:36: SystemError

Any idea what I need to change? My config looks like:

brownie-network-config.yaml

live:
  - name: Ethereum
    networks:
      - name: Standalone Ganache
        id: myganache
        host: http://127.0.0.1:8575
        chainid: 1
        timeout: 180
        explorer: https://api.etherscan.io/api

scripts/test.sh has brownie test --network myganache "$@"

mikeseese commented 4 years ago

Nevermind, it appears that if I'm already ganache on the same port brownie won't try to launch it

mikeseese commented 4 years ago

Alright, I have a pretty stable way to reproduce this issue and debug what's going on. Some preliminary findings:

If I run ganache in a separate process and run the test, I receive the error as stated in this issue. If i quit brownie, brownie will revert a bunch of snapshots to "revert" the ganache change back to the start. If I run the test again without restarting ganache, I get a different error:

>       arbitrage_tx = argobytes_owned_vault.atomicArbitrage(
            address_zero, argobytes_atomic_trade, address_zero, [address_zero], value, encoded_actions, {'from': accounts[1]})
E       brownie.exceptions.VirtualMachineError: revert: UniswapV1Action.tradeEtherToToken -> IUniswapExchange.ethToTokenTransferInput: reverted without a reason
E       Trace step -1, program counter 1663:
E         File "contracts/ArgobytesOwnedVault.sol", line 175, in ArgobytesOwnedVault.atomicArbitrage:    
E               // TODO: confirm that this actually saves us gas!
E               freeGasTokens(gas_token, initial_gas);
E       
E               revert(reason);
E           } catch (
E               bytes memory /*lowLevelData*/
E           ) {

tests/test_uniswap_v1_arbitrage.py:54: VirtualMachineError

This is interesting because it's the same error that the call trace points to when I ran the test in ganache the first time. Digging into how debug_traceTransaction works in ganache, it looks like we recreate a block from the parent block's state trie. This is sane in theory, but forking has a way of not managing state properly in a historical sense.

I tried my changes in #613 and it's still not working. I'm going to continue digging into this specific issue a tad further, but my hunch is that solving other forking issues will solve this issue

mikeseese commented 4 years ago

@WyseNynja are we able to run these tests on ganache without forking? Like deploying any contracts we need to and running tests against those on a completely fresh ganache state?

BlinkyStitt commented 4 years ago

That sounds like some good progress!

The tests could be rewritten to not depend on forking mainnet, but they would have to deploy some ERC20s and Uniswap/Kyber and bootstrap them with liquidity. That's how the early versions of my code did it, but it was fragile and done by a bunch of bash scripts that glued together their deploy scripts.

This test doesn't use a real exchange, but it does use all of my contracts: https://github.com/SatoshiAndKin/argobytes-contracts-brownie/blob/03befdc4f87f2f4ceefc35885a98ed869d807bf4/tests/test_argobytes_owned_vault.py#L30

haltman-at commented 4 years ago

I assume my earlier #605 is the same issue as this?

mikeseese commented 4 years ago

You are correct @haltman-at, I'll mark that one as a duplicate since this one is older (it was originally on the ganache-cli repo so that's probably why you didn't find it when you made #605)

However, I will use your #605 example to try to figure out the common root cause here. Thanks for letting me know!

mikeseese commented 4 years ago

@mds1 commented in #571 with reproduction steps that point to very similar reproduction steps that this issue has. I believe #571 was originally calling out the same issue, but it got shifted to solving a different problem with a similar symptom

I've put @mds1's comment below so it's easy for me to see all of the relevant recent information quickly

My current plan of attack here is to study both of these reproduction steps to understand the root issue and solve that. I don't believe this has to do with reentrance, but storage lookups are not adjusting as they should and are causing something to go awry and hit a piece of code that says you reentered

I'm using ganache-core 2.11.3-beta.0, and it seems I'm still seeing this bug in certain cases.

Steps to reproduce:

  1. Clone this repo at the linked commit
  2. Install packages with yarn
  3. Create file called .env with INFURA_ID=yourInfuraId
  4. Run tests with yarn test

In step 4, only two tests in batch-zkSync-deposit-test.js will run. The first will pass, and the second will fail with Error: Returned error: VM Exception while processing transaction: revert ReentrancyGuard: reentrant call. We can verify there is no reentry as follows:

  1. Modify line 116 to it.skip to skip that test. Run tests again, and our previously failing test now passes
  2. Undo the previous step. Now switch the order of these two tests (line 116 and line 125). The second test fails with the same error, even though both tests pass when run individually. So something is odd with the ordering of the tests here

The reentrant call error is from the zkSync contract, found here.

The full console output from the error is below:

Error: Returned error: VM Exception while processing transaction: revert ReentrancyGuard: reentrant call -- Reason given: ReentrancyGuard: reentrant call.
     at PromiEvent (node_modules/@truffle/contract/lib/promievent.js:9:30)
      at TruffleContract.deposit (node_modules/@truffle/contract/lib/execute.js:169:26)
      at Context.<anonymous> (test/batch-zkSync-deposit-test.js:124:46)
      at processTicksAndRejections (internal/process/task_queues.js:97:5)

It seems this has something to do with the use of evm_revert. In the beforeEach and afterEach hooks we save and restore the ganache state using evm_snapshot and evm_revert. If you comment out the evm_rever functionality (89 and 102) the above error does not happen.

I also just noticed I'm missing some awaits in the beforeEach hook, but adding those in does not resolve this issue

mikeseese commented 4 years ago

As you alluded to @mds1, I believe that snapshots/reverts are not handled properly in forking. I believe this is at a minimum affecting all storage, but it could also be an issue with how we handle storage deletes in between snapshot/revert. I'm got a ganache-core reproducing the error, so we're nearing a fix!

mikeseese commented 4 years ago

Turns out my test was incorrectly written and actually does work, so I still don't have a unit test that reproduces this. I did some refactoring that I was hoping was going to fix issues, but alas it does not. Investigating further to figure out exact root cause

mikeseese commented 4 years ago

Giving a little update here. I still don't have a unit test that reproduces the issues from @mds1's repo, but I was able to get a quick test setup that allowed me to debug it. I'm happy to say that I have code that resolves the issue within @mds1's repo! Early next week, I'll test the changes against @WyseNynja's repo to see if I killed 2 birds with 1 stone. Regardless, we'll look at making a beta release sometime next week

Hope yall have a good Labor Day!

mikeseese commented 4 years ago

Looks like I did not solve @WyseNynja's issue which is specific to debug_traceTransaction. I will be moving @mds1's issue (again haha) to #624 since his were specifically due to snapshots (which probably partially affected this issue)

We'll go forward with a beta release for that as I figure out debug_traceTransaction

BlinkyStitt commented 4 years ago

Thanks for all your hard work!

mikeseese commented 4 years ago

Quick update here: I've figured out the root cause of @WyseNynja's bug (at least the next hurdle haha). I can reproduce it in a test, and hoping to get over this one soon!

mikeseese commented 4 years ago

image

Seems like I'm able to get that one test to pass @WyseNynja! Hoping we can get a beta release out shortly after PR reviews

mikeseese commented 4 years ago

This was released in https://github.com/trufflesuite/ganache-core/releases/tag/v2.12.2-beta.0

mikeseese commented 4 years ago

@WyseNynja have you been able to test this yet? Are your forking issues resolved? Looks like it also made into a stable release a couple weeks ago: https://github.com/trufflesuite/ganache-core/releases/tag/v2.13.0 | https://github.com/trufflesuite/ganache-cli/releases/tag/v6.12.0

BlinkyStitt commented 4 years ago

Yes! My tests so far are much better. I haven't had time to finish them all (been working on proxy contracts instead), but the ones that were failing are passing now. Thank you!

On Oct 26, 2020, at 10:40 AM, Mike Seese notifications@github.com wrote:

 @WyseNynja have you been able to test this yet? Are your forking issues resolved? Looks like it also made into a stable release a couple weeks ago: https://github.com/trufflesuite/ganache-core/releases/tag/v2.13.0 | https://github.com/trufflesuite/ganache-cli/releases/tag/v6.12.0

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub, or unsubscribe.

mikeseese commented 4 years ago

This is awesome; thanks!