Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

debug_traceCall against "pending" uses empty state #24830

Closed
Anti83 opened this issue May 6, 2022 · 23 comments · Fixed by #24871
Closed

debug_traceCall against "pending" uses empty state #24830

Anti83 opened this issue May 6, 2022 · 23 comments · Fixed by #24871
Labels

Comments

@Anti83
Copy link

Anti83 commented May 6, 2022

System information

Version: 1.10.17-stable
Git Commit: 25c9b49
Architecture: amd64
Go Version: go1.18

Expected behaviour

Expected to traceCall pending transaction in context of pending block. I know about double exectution problem, but still need to trace against pending.

Actual behaviour

Every transaction I try to debug_traceCall against "pending" fails with "tracing failed: insufficient funds for gas * price + value: address 0x.. have 0 want 7149415673190000". It's always have 0 even when address has a lot.

Steps to reproduce the behaviour

Get transaction from subscription to pendingTransactions, try to debug_traceCall against "pending".
debug_traceCall against "latest" works fine.
eth_call against "pending" also works fine.
but debug_traceCall against "pending" always fails.

Backtrace

[backtrace]

When submitting logs: please submit them as text and not screenshots.

UPDATE:
eth_call against "pending" also does NOT work right. I think it uses "latest" not "pending" state. At least it uses maxFeePerGas from latest not pending

@Anti83 Anti83 added the type:bug label May 6, 2022
@Anti83 Anti83 changed the title debug_traceCall against "pending" fails with "tracing failed: insufficient funds for gas * price + value: address 0x.. have 0 want 7149415673190000" debug_traceCall against "pending" fails with "tracing failed: insufficient funds for gas * price + value: address 0x.. have 0 want ..." May 6, 2022
@holiman
Copy link
Contributor

holiman commented May 11, 2022

Repro:

[user@work go-ethereum]$ geth --dev console
...
> debug.traceCall({from: eth.accounts[0], to: eth.accounts[0], value:"0x1", gasPrice: "0xffffffff", gas: "0xffff"}, "latest")
{
  failed: false,
  gas: 21000,
  returnValue: "",
  structLogs: []
}
> debug.traceCall({from: eth.accounts[0], to: eth.accounts[0], value:"0x1", gasPrice: "0xffffffff", gas: "0xffff"}, "pending")
WARN [05-11|16:47:47.443] Served debug_traceCall                   reqid=23 duration=8.628038ms  err="tracing failed: insufficient funds for gas * price + value: address 0x8fbf6B1D5f2Aa3ce6cfB2B8247909802BE916F71 have 0 want 281470681677826"
Error: tracing failed: insufficient funds for gas * price + value: address 0x8fbf6B1D5f2Aa3ce6cfB2B8247909802BE916F71 have 0 want 281470681677826
        at web3.js:6365:37(47)
        at send (web3.js:5099:62(35))
        at <eval>:1:16(21)

@holiman
Copy link
Contributor

holiman commented May 11, 2022

Heh.. so what happens is that we do a tracing with the 'pending' block, with the following data;

block=1 hash=f97f11..637fc2 root=000000..000000

The stateroot is 0x000..00.
Later on, we try to get the state for this stateroot, by calling

		statedb, err = eth.blockchain.StateAt(block.Root())

Which returns a statedb, no errors!

Why? Because when opening a trie and resolving the root:

	if root != (common.Hash{}) && root != emptyRoot {
		rootnode, err := trie.resolveHash(root[:], nil)
		if err != nil {
			return nil, err
		}
		trie.root = rootnode
	}

So it returns a totally empty statedb, since root == (common.Hash{})

@holiman holiman changed the title debug_traceCall against "pending" fails with "tracing failed: insufficient funds for gas * price + value: address 0x.. have 0 want ..." debug_traceCall against "pending" uses empty state May 11, 2022
@Anti83
Copy link
Author

Anti83 commented May 11, 2022

eth_call against "pending" also does NOT work right. I think it uses "latest" not "pending" state. At least it uses maxFeePerGas from latest not pending.
UPDATE: eth_call against "pending" uses block number of pending but maxFeePerGas from latest...

@holiman
Copy link
Contributor

holiman commented May 11, 2022

My 5c is that we should either make it work, or explicitly reject it with an error.

@holiman
Copy link
Contributor

holiman commented May 12, 2022

IMO we should take a holistic approach with all the RPC call types, and try to be consistent in handling pending.
https://gist.github.com/holiman/427dde9faf552e2f01db27a8879ab331
Please help me fill out the gist with all of them

@holiman
Copy link
Contributor

holiman commented May 12, 2022

It seems debug_traceCall is the odd one out, since the api backend for that doesn't have the method StateAndHeaderByNumber(ctx, blockNr), which contains a shortcut to retrieve the pending. Should be not too difficult (and not totally trivial either) to make it work for that method, if we want it to.

@Anti83
Copy link
Author

Anti83 commented May 12, 2022

debug_traceCall against pending would be a life saver for me.
I am monitoring several MEV contracts. Trying to trace(understand what it is doing) their transactions while it is still pending. Before I was just making debug_traceCall against latest(transactions were behaving in same manner in latest like in execution), but recently these contracts added "protection" against such tracing(comparing blockNumber and/or timestamp), so in tracing against latest its doing one thing, but in reality doing another.
So my option was using hardhat/ganache, forking every block and executing transaction in fork, this was buggy and slow.
Another option is wait until interested transaction will get into my pending block(can take several seconds) and make debug_traceBlockByNumber, but that also slow.
Maybe there is another way to trace transaction in the context of pending block?

@holiman
Copy link
Contributor

holiman commented May 13, 2022

Tracing on pending will be quirky too. For one thing, after a while "interested transaction will get into my pending block" -- and this will make the tracing starting to fail, because it cannot be traced on top of itself.

debug_traceTransaction already supports state overrides, the idea being that you can tell it "balance of X is Y, and storage slot A has value C".

Sounds to me that what would be better in this particular usecase would be to extend the override capabilities, so you can, on top of latest state, also supply override block-context fields (timestamp, number, difficulty etc).

If we add that, it would (I think) make the override-capability pretty much complete. And if we had that, then we could just legitimately return an error when trying to trace on pending.

@holiman
Copy link
Contributor

holiman commented May 13, 2022

@Anti83 could you please try out #24871 a bit, see if it seems to work?

@Anti83
Copy link
Author

Anti83 commented May 13, 2022

Working on it. Thanks.

@Anti83
Copy link
Author

Anti83 commented May 13, 2022

I tested blockNumber and time and it works!
Thanks so much!

@Anti83
Copy link
Author

Anti83 commented May 14, 2022

Started to see a lot messages like these

WARN [05-14|18:02:50.410] Served debug_traceCall                   reqid=1055670 duration=49m7.255408233s  err="execution timeout"
WARN [05-14|17:21:00.563] Served debug_traceCall                   reqid=888612  duration=19m18.606349306s err="execution timeout" 

Some transactions are going through such debug fine, but some don't. For example
0x88a0b6b6818af7983c25f4fad92bf671adaad8f6315641c4fb9b7369834ecc9e (executed in block 14774248)
My node saw this transaction in block 14774247,
made a transaction object:

txToCheck =   {
  from: '0x8E17d7A5Eeb39E558021e0B5F75Ad60CF9a1a939',
  to: '0x8e60B2b96ea901BEb2cafd79b8D0eD249A5efd95',
  data: '0x00e7cb033de0a12e000693b5c08bbaf8000323130327a36854d2877702675e6ceb975b4a1dff9fb7baf4c91ea964669221f4bd31ea8212119f94a611fa969881cba3ea06fa3d1e64',
  value: '0x0',
  gas: '0x5e90f'
}

first executed eth_call against pending
it did not revert and then made a debug_traceCall against latest with blockoverrides number = 14774248
and only in block 14774286 came Error: Returned error: execution timeout
Most transactions are checked fine. Out of 19k transactions checked only 100 gave this error.
It seems to depend on smart contract because all transactions to same smart contract fail with this timeout error.
So debugging all transactions to 0x8e60B2b96ea901BEb2cafd79b8D0eD249A5efd95 contract give execution timeout error. Here is another such smart contract 0x9934ecf8a194a05e59a45838292ca4890120d396
Also node crushed after 10 hours of such debugging.

@ramsemune123

This comment was marked as spam.

@holiman
Copy link
Contributor

holiman commented May 14, 2022

Also node crushed after 10 hours of such debugging.

Please provide the crash log, if you have it

@Anti83
Copy link
Author

Anti83 commented May 15, 2022

Also node crushed after 10 hours of such debugging.

Please provide the crash log, if you have it

Node crashed again. I don't have log but node's last words were WARN this timeout error with duration = 3 hours and then "killed". I now restarted node with verbose 4 and will send log when it crashes.

@Anti83
Copy link
Author

Anti83 commented May 16, 2022

So node crashes like every 10 hours, there is not crash explanation in log started with verbose 4, log just stoped and in console message "killed".
So this node is making debug_traceCall on almost all transaction agains latest with overridden block to latest+1.
After 20 min first warn messages start appearing

WARN [05-15|08:20:12.614] Served debug_traceCall                   reqid=37302 duration=5m50.63610105s err="execution timeout"
WARN [05-15|08:20:12.614] Served debug_traceCall                   reqid=48388 duration=3m45.308692267s err="execution timeout"
WARN [05-15|08:20:12.614] Served debug_traceCall                   reqid=38944 duration=5m31.312695682s err="execution timeout"
WARN [05-15|08:20:12.614] Served debug_traceCall                   reqid=37372 duration=5m47.381590357s err="execution timeout"

The longer node works the higher duration= is, have seen one with duration=3 hours...

@holiman
Copy link
Contributor

holiman commented May 17, 2022

Exactly how are you invoking this method? Are you doing it sequentially, or just massively in parallel, with every tx you can find?

@Anti83
Copy link
Author

Anti83 commented May 17, 2022

I am subscribed to pendingTransactions, when get new hash I get transaction from hash(await web3.eth.getTransaction), then make first test it by await web3.eth.call against pending, then make await web3.debug_traceCall
So it is more like "massively in parallel".

@Anti83
Copy link
Author

Anti83 commented May 17, 2022

So 99% of all transaction pass debug_traceCall against latest with overriding to pending.
Others error with err="execution timeout" after different period.
Out of all transaction that error debug_traceCall 99% are mint transactions like
0x6c94504222ee14ebe325bb8166f9aca97d04b9ee133c46072c482f748ce2c5e7
0x73b30a31c5083834c529f871d8331e82fecc6c6714f08055087e5dd6eeee2d54
0x80a7aed880d4e0571c4f470e7b6c9721db2500f500e829f7f5b8c55fe0b2ff56

But not only. 0x8e60b2b96ea901beb2cafd79b8d0ed249a5efd95 this is trading smart contract and transactions to it also fail debugging. You can reproduce it
tr hash 0xc72839e9bd8e4ebba5c1176c0921d6bff80f297ed1f8a37cf9a77d26dae325d1


 let txForTrace = {
        "from": "0x2c86c0c46ab6d2c9fa186e9839689e9a4490a61f",
        "to": "0x8e60b2b96ea901beb2cafd79b8d0ed249a5efd95",
        "data": "0x002c80033df5d10200093f63aa0a19cc8002130332b62b1d7d1afa7b718fb893db30a3abc0cfc608aacfebb01e64",
        "gas": web3.utils.toHex(878383),
    }; 
    
    let debugResult = await web3.debug_traceCall(txForTrace, web3.utils.toHex("14791724"), {
        "tracer": "callTracer",
        "blockoverrides": {
            "number": web3.utils.toHex("14791725"),
        }
    });
console.log("debugResult ", debugResult);

@holiman
Copy link
Contributor

holiman commented May 19, 2022

Thanks for the feedback, indeed, this is reproducible. Fix incoming

@holiman
Copy link
Contributor

holiman commented May 19, 2022

The issue is fixed now. It was a case of BLOCKHASH, which due to this new 'redefinition' of NUMBER, it basically did a block by block lookup towards genesis. That is fixed in the PR now, please give it a spin again

@Anti83
Copy link
Author

Anti83 commented May 21, 2022

So far so good.
Thank you!

@Anti83
Copy link
Author

Anti83 commented Jun 1, 2022

Everything works fine!
Is it possible to make eth_call also support these overrides?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

5 participants
@ligi @holiman @Anti83 @ramsemune123 and others