search

foundry-rs / foundry

Foundry is a blazing fast, portable and modular toolkit for Ethereum application development written in Rust.
https://getfoundry.sh
Apache License 2.0
8.24k stars 1.73k forks source link

Anvil seems to hang/crash when submitting transactions through Metamask on a forked network. #1920

Closed sunwrobert closed 2 years ago

sunwrobert commented 2 years ago

Component

Anvil

Have you ensured that all of these are up to date?

What version of Foundry are you on?

forge 0.2.0 (dc83894 2022-06-11T00:06:34.928765727Z)

What command(s) is the bug in?

anvil

Operating System

Linux

Describe the bug

I'm trying to test submitting transactions through Metamask connected to anvil (localhost:8545).

This is the example anvil command I'm running:

anvil --fork-url="https://eth-mainnet.alchemyapi.io/v2/XXXXXXXXXXXXXXXXXXXXXXXXX" --fork-block-number=14812197 --port=8545 -b=5 --chain-id=1

Example steps I've done to reproduce:

  1. I fork a specific block, set the block time to be a certain interval
  2. Launch opensea.io and sign in with one of my wallets that has an NFT
  3. List the item and in the process, calling setApprovalForAll on the NFT
  4. Notice that the transaction never goes through and anvil just freezes up (No blocks are getting produced anymore every 5s, it just seems to completely freeze and hang)
mattsse commented 2 years ago

will likely be remedied with #1922 and https://github.com/foundry-rs/foundry/pull/1715

Vitalsine85 commented 2 years ago

I've been having the same issue but on Windows. Tried building from the PRs you mentioned but didn't have any luck.

sunwrobert commented 2 years ago

The foundry version getting released tonight should alleviate this, right?

mattsse commented 2 years ago

I'm actually not sure, I managed to reproduce some weird behavior in fork mode with metamask though but didn't check your opensea repro.

does this happen with simple transfers as well? then I could debug this more easily

also can you try running anvil prefixed with RUST_LOG=node,backend,api,rpc=warn anvil to get more logs? perhaps it's more obvious where it hangs

sunwrobert commented 2 years ago

@mattsse Transfers seem to work fine. I ran anvil with the prefix you mentioned and it crashed even before I submitted any tx (using the Opensea reproduction, where we just ask the user to approve their token)

2022-06-14T22:54:52.091743Z TRACE node: mined block 14962718
2022-06-14T22:54:52.091752Z TRACE node: pruned transaction markers PruneResult { promoted: [], failed: [], pruned: [], }
2022-06-14T22:54:56.860176Z  INFO node::user: eth_estimateGas
2022-06-14T22:54:56.860205Z TRACE backend: calling from [Some(0xFOO_ADDRESS)] fees=FeeDetails { gas_price: Some(0), max_fee_per_gas: Some(0), max_priority_fee_per_gas: None }
2022-06-14T22:54:56.860222Z TRACE backend: calling with tx env from=0xFOO_ADDRESS gas-limit=30000000, gas-price=30000000
2022-06-14T22:54:56.860432Z TRACE backendhandler: received request basic address=0x0000000000000000000000000000000000000002
2022-06-14T22:54:56.860551Z TRACE backendhandler: received request basic address=0x0000000000000000000000000000000000000003
2022-06-14T22:54:56.860638Z TRACE backendhandler: received request basic address=0x0000000000000000000000000000000000000001
2022-06-14T22:54:56.863531Z TRACE backendhandler: received request basic address=0x0000000000000000000000000000000000000004
2022-06-14T22:54:56.864359Z TRACE backendhandler: received request basic address=0x0000000000000000000000000000000000000009
2022-06-14T22:54:56.864500Z TRACE backendhandler: received request basic address=0x0000000000000000000000000000000000000006
2022-06-14T22:54:56.864628Z TRACE backendhandler: received request basic address=0x0000000000000000000000000000000000000007
2022-06-14T22:54:56.864762Z TRACE backendhandler: received request basic address=0x0000000000000000000000000000000000000008
2022-06-14T22:54:56.864891Z TRACE backendhandler: received request basic address=0x0000000000000000000000000000000000000005
2022-06-14T22:54:56.865027Z TRACE backendhandler: received request basic address=0xFOO_ADDRESS
2022-06-14T22:54:56.865163Z TRACE backendhandler: received request basic address=0x3f53082981815ed8142384edb1311025ca750ef1
2022-06-14T22:54:56.865172Z TRACE backendhandler: preparing account request, address=0x3f53082981815ed8142384edb1311025ca750ef1
2022-06-14T22:54:57.091476Z TRACE backend: creating new block with 0 transactions

and yeah, output stops there and no blocks are being produced anymore

wdv4758h commented 2 years ago

I have anvil running with fork mode set to Ethereum goerli test net (via https://rpc.goerli.mudit.blog). And I think I catch a kind of crash that's related to this issue.

here is the logs before it crashed:

2022-06-15T02:53:04.705830Z  INFO node::user: eth_getBlockByNumber
2022-06-15T02:53:04.705840Z TRACE backend: get block by number Number(7060944)
2022-06-15T02:53:04.945177Z  INFO node::user: eth_networkId
thread 'fork-backend-thread' panicked at 'Failed to get account for 0xde50…0566
ProviderError(JsonRpcError(JsonRpcError { code: -32000, message: "missing trie node 380ab0bdec2bc4d7d9011ccdac1691d3ac689a96e9be733ff62c823a4c7a4626 (path )", data: None }))', /opt/foundry/evm/src/executor/fork/backend.rs:275:33
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

using container with tag nightly-123ad0a427dc938a0a911eae3332de6576370a51

mattsse commented 2 years ago

thanks for these

what endpoints are you using? alchemy?

@wdv4758h

thread 'fork-backend-thread' panicked at 'Failed to get account for 0xde50…0566 ProviderError(JsonRpcError(JsonRpcError { code: -32000, message: "missing trie node 380ab0bdec2bc4d7d9011ccdac1691d3ac689a96e9be733ff62c823a4c7a4626 (path )", data: None }))', /opt/foundry/evm/src/executor/fork/backend.rs:275:33

this is an error occurred at the fork provider which failed to return the account does, https://rpc.goerli.mudit.blog/ serve archive state?

wdv4758h commented 2 years ago

does, https://rpc.goerli.mudit.blog/ serve archive state?

Not sure, I just grab from the open rpc list on the repo for testing: https://github.com/goerli/testnet Maybe can try other endpoints, I will try some more.

But I did successful fetch the account balance before. Maybe that open rpc endpoint is not so stable and fail to return sometime?

Is it possible to have error handling other than crash? Like have multiple fork urls can try, or retry later, or fail this request but don't crash.

mattsse commented 2 years ago

there's really nothing we can do when the endpoint refuses to serve data that's required by the evm.

I can however recommend alchemy endpoints (should work for goerli) we have ratelimit support for alchemy, infura should also work, since they added archive state support recently

sunwrobert commented 2 years ago

I'm using alchemy yes. And we're using the exact same block and alchemy endpoint that we're using for our same tests that are using Hardhat and Hardhat handles it fine for the most part, so it does seem like an underlying Anvil issue

mattsse commented 2 years ago

thanks, makes sense.

will do a more thorough investigation tonight.

ntop001 commented 2 years ago

Does this fixed or not?

mattsse commented 2 years ago

possibly,

1996 is included in latest nightly

sunwrobert commented 2 years ago

I'll test today.

sunwrobert commented 2 years ago

@mattsse Still seems to be crashing, but the output is slightly different from before. Last output is here:

project-ethereum-mainnet-1  | 2022-06-18T02:23:46.361780Z TRACE backendhandler: received request basic address=0x0f5d2fb29fb7d3cfee444a200298f468908cc942
project-ethereum-mainnet-1  | 2022-06-18T02:23:46.361795Z TRACE backendhandler: preparing account request, address=0x0f5d2fb29fb7d3cfee444a200298f468908cc942
project-ethereum-mainnet-1  | 2022-06-18T02:23:46.387815Z TRACE backendhandler: preparing storage request, address=0x0f5d2fb29fb7d3cfee444a200298f468908cc942, idx=85852922129748126525582139704543950817797612144698387788019680196016720668660
project-ethereum-mainnet-1  | 2022-06-18T02:23:46.403578Z TRACE backendhandler: received request basic address=0x0f513ffb4926ff82d7f60a05069047aca295c413
project-ethereum-mainnet-1  | 2022-06-18T02:23:46.403594Z TRACE backendhandler: preparing account request, address=0x0f513ffb4926ff82d7f60a05069047aca295c413
project-ethereum-mainnet-1  | 2022-06-18T02:23:46.430382Z TRACE backendhandler: preparing storage request, address=0x0f513ffb4926ff82d7f60a05069047aca295c413, idx=96420846711379471239742231809739538133531898153254452663926717729605829919804
project-ethereum-mainnet-1  | 2022-06-18T02:23:46.450619Z TRACE backendhandler: received request basic address=0x5bc7e5f0ab8b2e10d2d0a3f21739fce62459aef3
project-ethereum-mainnet-1  | 2022-06-18T02:23:46.450634Z TRACE backendhandler: preparing account request, address=0x5bc7e5f0ab8b2e10d2d0a3f21739fce62459aef3
project-ethereum-mainnet-1  | 2022-06-18T02:23:46.475304Z TRACE backendhandler: preparing storage request, address=0x5bc7e5f0ab8b2e10d2d0a3f21739fce62459aef3, idx=85852922129748126525582139704543950817797612144698387788019680196016720668660
project-ethereum-mainnet-1  | 2022-06-18T02:23:46.496208Z TRACE backendhandler: received request basic address=0xebbdf302c940c6bfd49c6b165f457fdb324649bc
project-ethereum-mainnet-1  | 2022-06-18T02:23:46.496224Z TRACE backendhandler: preparing account request, address=0xebbdf302c940c6bfd49c6b165f457fdb324649bc
project-ethereum-mainnet-1  | 2022-06-18T02:23:46.532070Z TRACE backendhandler: preparing storage request, address=0xebbdf302c940c6bfd49c6b165f457fdb324649bc, idx=31496489287106300060404277735598007218836779598311300939303859377159949310958
project-ethereum-mainnet-1  | 2022-06-18T02:23:46.550630Z TRACE backendhandler: received request basic address=0x2604fa406be957e542beb89e6754fcde6815e83f
project-ethereum-mainnet-1  | 2022-06-18T02:23:46.550649Z TRACE backendhandler: preparing account request, address=0x2604fa406be957e542beb89e6754fcde6815e83f
project-ethereum-mainnet-1  | 2022-06-18T02:23:46.595170Z TRACE backendhandler: preparing storage request, address=0x2604fa406be957e542beb89e6754fcde6815e83f, idx=85852922129748126525582139704543950817797612144698387788019680196016720668660
project-ethereum-mainnet-1  | 2022-06-18T02:23:46.617975Z TRACE backendhandler: received request basic address=0xe41d2489571d322189246dafa5ebde1f4699f498
project-ethereum-mainnet-1  | 2022-06-18T02:23:46.617990Z TRACE backendhandler: preparing account request, address=0xe41d2489571d322189246dafa5ebde1f4699f498
project-ethereum-mainnet-1  | 2022-06-18T02:23:46.640400Z TRACE backendhandler: preparing storage request, address=0xe41d2489571d322189246dafa5ebde1f4699f498, idx=27411761229957352210526562980858515891629979690125260259452419220024153541820
project-ethereum-mainnet-1  | 2022-06-18T02:23:46.660137Z TRACE backendhandler: received request basic address=0xb563300a3bac79fc09b93b6f84ce0d4465a2ac27
project-ethereum-mainnet-1  | 2022-06-18T02:23:46.660152Z TRACE backendhandler: preparing account request, address=0xb563300a3bac79fc09b93b6f84ce0d4465a2ac27
project-ethereum-mainnet-1  | 2022-06-18T02:23:46.672466Z  INFO node::user: eth_chainId

If you want the full test log, I've published it in this gist

ntop001 commented 2 years ago

@mattsse Sir, there is an easy way to reproduce this problem. Here is a Link from OpenSea(buy an NFT): https://etherscan.io/tx/0x4b23df29d89e5ddae74aff791fc38f2227feb952420c212f5987590f4db3c2b1 The tx is committed at block: 14983339

You can fork the mainnet just before this block(like: 14983338), and copy the call-data from the tx, then constructs a new tx with the copied calldata. Then, you'll see the result.

Hope this'll help you.

wdv4758h commented 2 years ago

Oh I might find out the root cause of my previous anvil crash. I was using non-fork mode for testing, which chain id was 33137. And I update to use fork mode (under same domain), which chain id is 5 now. And I forgot to update the chain id setting on MetaMask's custom network. When it sends request to anvil with expecting chain id 33137, anvil can't fetch some data and causes Failed to get account ... then crash.

Not sure how detail things work, but it looks like this.

2547881370 commented 2 years ago

Is the problem fixed? I also encountered this problem today. Metamask crashed

mattsse commented 2 years ago

can you please check your metamask chain id settings for localhost, default anvil chain id is 31337

2547881370 commented 2 years ago

你能检查一下你的 localhost 的 metamask 链 id 设置吗，默认的 anvil 链 id 是 31337 image

This is my options

anvil -f https://bsc-mainnet.nodereal.io/v1/a9d5920ea85349c298ee543d3d4922ac --chain-id 56 --gas-limit 1200000000 --gas-price 2000000000000 --fork-block-number 22070910

image

image

mattsse commented 2 years ago

can reproduce this with bsc.

but after looking at the logs, it seems requests are handled instantly by anvil, so I'm not sure while mm hangs...

somehow this seems to be related to mining mode.

if you select an auto mine interval, (-b 1) 1sec blocktime then the problem seems to go away.

2547881370 commented 2 years ago

Thank you. I'll try again

2547881370 commented 2 years ago

can reproduce this with bsc.

but after looking at the logs, it seems requests are handled instantly by anvil, so I'm not sure while mm hangs...

somehow this seems to be related to mining mode.

if you select an auto mine interval, (-b 1) 1sec blocktime then the problem seems to go away.

After setting the block interval, it is really successful, but this is not my ideal state;

My ideal state is that each transaction will automatically generate a block

mattsse commented 2 years ago

sorry about that, not obvious to me at this point what's causing this, or why this goes away with interval mining. I don't see a stuck request in the logs, unsure whether this related to MM internals...

2547881370 commented 2 years ago

sorry about that, not obvious to me at this point what's causing this, or why this goes away with interval mining. I don't see a stuck request in the logs, unsure whether this related to MM internals...

Well, thank you for your answer

sandybradley commented 1 year ago

Had the same issue. Setting the block mining time fixed it. Thank you!

BhautikChudasama commented 3 months ago

I am getting a similar issue, when i am doing transactions using metamask it goes into the queue, I had tried with setting block mining time, but it is not working.

anvil --fork-chain-id=17000 --fork-url=https://virtual.holesky.rpc.tenderly.co/VIRTUAL_NET_ID --fork-block-number=1873206 --gas-limit=120000
Screenshot 2024-07-18 at 7 46 42 PM
BhautikChudasama commented 3 months ago

Here is the log, It Seems like it recorded the transaction but the next block is created with 0 transactions.

2024-07-18T15:34:15.686946Z TRACE backend::fees: updated base fee 1
2024-07-18T15:34:15.686950Z TRACE backend::fees: updated blob base fee BlobExcessGasAndPrice { excess_blob_gas: 0, blob_gasprice: 1 }
2024-07-18T15:34:15.686972Z TRACE node: mined block 1873234
2024-07-18T15:34:15.744301Z  INFO node::user: eth_getBalance
2024-07-18T15:34:15.744594Z  INFO node::user: eth_getBalance
2024-07-18T15:34:15.744662Z  INFO node::user: eth_getBalance
2024-07-18T15:34:16.742452Z  INFO node::user: eth_blockNumber
2024-07-18T15:34:25.673939Z  INFO node::user: eth_sendRawTransaction
2024-07-18T15:34:25.674446Z TRACE node: Added transaction: [0x12ff6d571b5373a2c237f966fe05c5c02cce8c48131017396fd39b5b2941f79e] sender=0x368cba3e4b70af4013e24bba46342c856dcb8b74
2024-07-18T15:34:25.686591Z TRACE backend: creating new block with 0 transactions
2024-07-18T15:34:25.686806Z TRACE backend: Mined block 1873235 with 0 tx []
2024-07-18T15:34:25.686861Z  INFO node::user: 
2024-07-18T15:34:25.686870Z  INFO node::user:     Block Number: 1873235
2024-07-18T15:34:25.686875Z  INFO node::user:     Block Hash: 0x1a6b2fc09bd21d732b581aca01af2e2e12e453eb6a8437479ec0e57635b0c3e1
2024-07-18T15:34:25.686880Z  INFO node::user:     Block Time: "Sat, 6 Jul 2024 06:07:23 +0000"