Go-ethereum: Geth trace parser providing invalid traces

[juliankoh]

Hi! I'm getting invalid traces when using the call_tracer geth tracing paser. Specifically, it is outputting a trace that should change balance, even though there is no actual balance change on-chain.

System information

Geth version: geth version v1.9.18
OS & Version: OSX
Commit hash : -

Expected behaviour

Using the aforementioned tracer on this transaction, I get the following output:

{
  "type": "CALL",
  "from": "0x66fdfd05e46126a07465ad24e40cc0597bc1ef31",
  "to": "0x6c06b16512b332e6cd8293a2974872674716ce18",
  "value": "0x0",
  "gas": "0x1a466",
  "gasUsed": "0x1dc6",
  "input": "0x2e1a7d4d00000000000000000000000000000000000000000000000014d1120d7b160000",
  "output": "0x",
  "time": "1.278236ms",
  "calls": [
    {
      "type": "CALL",
      "from": "0x6c06b16512b332e6cd8293a2974872674716ce18",
      "to": "0x66fdfd05e46126a07465ad24e40cc0597bc1ef31",
      "value": "0x14d1120d7b160000",
      "input": "0x"
    }
  ]
}

This implies that there should be a transfer of value 0x14d1120d7b160000, but Etherscan shows that this balance change does not happen.

Furthermore, tracing that same transaction using Parity's node shows that the subcall does not actually happen. Here are Parity's traces:

{
  "jsonrpc": "2.0",
  "result": [
    {
      "action": {
        "callType": "call",
        "from": "0x66fdfd05e46126a07465ad24e40cc0597bc1ef31",
        "gas": "0x1a466",
        "input": "0x2e1a7d4d00000000000000000000000000000000000000000000000014d1120d7b160000",
        "to": "0x6c06b16512b332e6cd8293a2974872674716ce18",
        "value": "0x0"
      },
      "blockHash": "0xc91e2c6efc40c303a969cace595c31a5ea810986dbbc134c6825fa8b6b226113",
      "blockNumber": 24974,
      "result": {
        "gasUsed": "0x1dc6",
        "output": "0x"
      },
      "subtraces": 0,
      "traceAddress": [],
      "transactionHash": "0x73ccf1fbebdaa2bc4d33e769373fd9cf65365666245736a11bc773b32ab9f92a",
      "transactionPosition": 1,
      "type": "call"
    }
  ],
  "id": 1
}

Initially, I thought that I could consider this call invalid because it did not have gasUsed populated. However, I found an example of another transaction where the traces look identical to the one I posted above, but actually does apply a balance change as you can see on Etherscan.

Here are the traces for that transaction:

{
  "type": "CALL",
  "from": "0xb5f5999a52904d4f3482fa31baa52f7be1984906",
  "to": "0x536e7faca074d21f0830c936e141a7271d09b0c9",
  "value": "0x0",
  "gas": "0x2b168",
  "gasUsed": "0x88f9",
  "input": "0xb5c5f6720000000000000000000000008f480474b014ea63d4fe5e52478e833fb9e8f93800000000000000000000000000000000000000000000000006f05b59d3b200000000000000000000000000000000000000000000000000000000000000030d40",
  "output": "0x",
  "time": "2.063668ms",
  "calls": [
    {
      "type": "CALL",
      "from": "0x536e7faca074d21f0830c936e141a7271d09b0c9",
      "to": "0x8f480474b014ea63d4fe5e52478e833fb9e8f938",
      "value": "0x6f05b59d3b20000",
      "input": "0x"
    }
  ]
}

Actual behaviour

Showing trace in a transaction although it never happened on-chain.

Steps to reproduce the behaviour

To reproduce, use this call_tracer in the debug_traceTransaction endpoint, with this transaction on Ropsten

Backtrace

[backtrace]

[holiman]

Etherscan/parity says that the internal call to 0x66fdfd05e46126a07465ad24e40cc0597bc1ef31 has 0 value:

https://ropsten.etherscan.io/vmtrace?txhash=0x73ccf1fbebdaa2bc4d33e769373fd9cf65365666245736a11bc773b32ab9f92a&type=parity

[holiman]

In order to debug this, we'll have to sync ropsten up to block 24974, which shouldn't take too long, and then get a full trace (not the abriged version) to see what exactly happens here.

[holiman]

So, there is indeed a call like geth says:

However, looking at the next op, it places a 0 on the stack, meaning the call failed.

So indeed, the call did not change the state for the call-destination, nor did it execute any code on the recipient. It's a failed call (I'm not sure why it failed though)

[holiman]

I'm 99% certain that the internal call failed because it tried to send value, but didn't actually have balance.

[holiman]

So, before I "fix" this, I think we should first establish whether the parity-behaviour is correct. I can see the point in that, since if the call fails due to too low balance for call, it's an "insta-fail" which does not cause any state changes on the recipient.
On the other hand, one could argue that the geth trace is more correct.

@karalabe -- thoughts?

[karalabe]

I think it's nice to know there was a call attempt, though in that case we should also list an error accordingly if it failed. But I think we're entering limit-territory for the tracers. We only have a capture method for before (or after, don't remember) an opcode, but to properly capture the failure here I think we'd need both.

[karalabe]

I distinctly remember that the call tracer has some limitation when 0 opcodes get executed within a call. E.g. we don't know how much gas was allotted to the inner call because we only see the outer gas, then a success/fail. but never the inner one.

[holiman]

E.g. we don't know how much gas was allotted to the inner call because we only see the outer gas, then a success/fail. but never the inner one.

Yes, same applies to calls to precompiles. There's no internal tracing, so we can't know if it executed or failed... Don't know how parity handles that case.

[holiman]

( I mean, we can know that it failed based on the retvalue, but not really much else)

[juliankoh]

@holiman @karalabe hey! wondering if we came to any consensus here on what the path forward is? From a user perspective, I'd like this to be as similar as possible to Parity's, since majority of the industry uses their nodes for tracing.

[brockmiller]

Following along with this issue as well. Do we think it is possible to update Geth's response here such that we can at least determine whether the call succeeded or failed (even if we can't provide the exact error)?

[xrn]

Great job! I have a question, can I use the call_tracer with Geth archive node or I need a different type of syncing?

[holiman]

Well, the archive node means it can instantly serve you the state for any block (which is good). If you have a non-archive node, in order to find the state for block X, it might have to go back to X-N to find the state, and then chug through N blocks to obtain the state again (you can tune how large N can be with the reexec-parameter).

And lastly, if you did a fast-sync, your first state is genesis and second is at pivot_block, so if you try tracing something earlier than pivot, the node would essentially have to do a full-sync from genesis to obtain the state, so that's a no-go.