Cannot run trace.block() on block 2396379 on archival node

[afmsavage]

System information

Geth version: CoreGeth/v1.12.1-stable-04d026e2
OS & Version: alpine:latest image
Commit hash : (if develop)

Expected behaviour

A successful trace of this block.

Actual behaviour

A web3js error:

> trace.block('2396379')
Error: method handler crashed
    at web3.js:6347:37(47)
    at web3.js:5081:62(37)
    at <eval>:1:12(4)

Steps to reproduce the behaviour

Get a Ethereum Classic Mainnet archival node fully synced. Will include my run command below as well. In the javascript console, run trace.block('2396379')

I have tested this on two seperate ETHClassic archival nodes as well.

Run Command

geth --syncmode full --gcmode archive --http --http.addr 0.0.0.0 --http.corsdomain * --http.api db,eth,net,web3,debug,trace --http.port 8545 --http.vhosts * --maxpeers 50 --ws --ws.addr 0.0.0.0 --ws.origins * --ws.port 8545 --metrics --pprof --pprof.addr 0.0.0.0 --pprof.port 6060 --datadir /ethereum/ --cache 4096 --networkid 1 --classic --verbosity 4 --snapshot=false

Backtrace

[backtrace]

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

[ziogaschr]

Hello @afmsavage.

The issue with this block is that the tracer timeouts after 30seconds (default).
For getting the tracer output you can run this command: trace.block('2396379', {"timeout": "60s"})

This issue came back twice (once to myself internally) and we will have to consider giving back a better error, but before doing that we have to check if it breaks existing functionalities on services using this API.

[afmsavage]

Just tried with 60s and even larger values but am still getting the same errors. What's weird is that I timed the errors and it was erroring out right around 50 seconds for all 3.

> trace.block('2396379', {"timeout": "60s"})
Error: Post "http://localhost:8545": EOF
	at web3.js:6347:37(47)
	at web3.js:5081:62(37)
	at <eval>:1:12(7)

> trace.block('2396379', {"timeout": "120s"})
Error: Post "http://localhost:8545": EOF
	at web3.js:6347:37(47)
	at web3.js:5081:62(37)
	at <eval>:1:12(7)

> trace.block('2396379', {"timeout": "240s"})
Error: Post "http://localhost:8545": EOF
	at web3.js:6347:37(47)
	at web3.js:5081:62(37)
	at <eval>:1:12(7)

[afmsavage]

Even with disabling some parts of the trace it is still not enough to get a return

> trace.block('2396379', {"timeout": "240s", "disableMemory": true, "disableStorage": true, "disableStack":true})
Error: Post "http://localhost:8545": EOF
	at web3.js:6347:37(47)
	at web3.js:5081:62(37)
	at <eval>:1:12(13)

> trace.block('2396379', {"timeout": "240s", "DisableMemory": true, "DisableStorage": true, "DisableStack":true})
Error: Post "http://localhost:8545": EOF
	at web3.js:6347:37(47)
	at web3.js:5081:62(37)
	at <eval>:1:12(13)```

[ziogaschr]

hmm, error here is different. Can you try running this command from within the node using geth's console?

edit: I think the issue here might be that web3.js in browser has a timeout at 50s. Can you try same call using cURL?

[afmsavage]

Those were directly on the node in the Javascript console.

[ziogaschr]

Can you please run this in console debug.verbosity(5) or start node with --verbosity 5, run the trace command and share the logs with me.
Thank you

[afmsavage]

Got this error.

ERROR[09-16|17:57:47.790] RPC method trace_block crashed: interface conversion: interface {} is nil, not json.RawMessage
goroutine 155068788 [running[]:
github.com/ethereum/go-ethereum/rpc.(*callback).call.func1(0xc0163c5360, 0xb, 0xc01752fd58)
    /core-geth/rpc/service.go:199 +0xba
panic(0x147c200, 0xc075d646c0)
    /usr/local/go/src/runtime/panic.go:969 +0x1b9
github.com/ethereum/go-ethereum/eth/tracers.(*TraceAPI).Block(0xc003f5f1c0, 0x20dea80, 0xc024cca280, 0x2490db, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
    /core-geth/eth/tracers/api_parity.go:216 +0x725
reflect.Value.call(0xc008bb2480, 0xc00888fe18, 0x13, 0x16250af, 0x4, 0xc04945c240, 0x4, 0x4, 0xc04945c270, 0xc01aa59110, ...)
    /usr/local/go/src/reflect/value.go:476 +0x8c7
reflect.Value.Call(0xc008bb2480, 0xc00888fe18, 0x13, 0xc04945c240, 0x4, 0x4, 0x16, 0x0, 0x0)
    /usr/local/go/src/reflect/value.go:337 +0xb9
github.com/ethereum/go-ethereum/rpc.(*callback).call(0xc008c93140, 0x20dea80, 0xc024cca280, 0xc0163c5360, 0xb, 0xc01aa59110, 0x2, 0x2, 0x0, 0x0, ...)
    /core-geth/rpc/service.go:205 +0x2c5
github.com/ethereum/go-ethereum/rpc.(*handler).runMethod(0xc01ecb5560, 0x20dea80, 0xc024cca280, 0xc07386e310, 0xc008c93140, 0xc01aa59110, 0x2, 0x2, 0x2)
    /core-geth/rpc/handler.go:389 +0x8a
github.com/ethereum/go-ethereum/rpc.(*handler).handleCall(0xc01ecb5560, 0xc01aa590b0, 0xc07386e310, 0x203006)
    /core-geth/rpc/handler.go:337 +0x294
github.com/ethereum/go-ethereum/rpc.(*handler).handleCallMsg(0xc01ecb5560, 0xc01aa590b0, 0xc07386e310, 0x20caf01)
    /core-geth/rpc/handler.go:298 +0x1be
github.com/ethereum/go-ethereum/rpc.(*handler).handleMsg.func1(0xc01aa590b0)
    /core-geth/rpc/handler.go:139 +0x46
github.com/ethereum/go-ethereum/rpc.(*handler).startCallProc.func1(0xc01ecb5560, 0xc05a66a4a0)
    /core-geth/rpc/handler.go:226 +0xd2
created by github.com/ethereum/go-ethereum/rpc.(*handler).startCallProc
    /core-geth/rpc/handler.go:222 +0x66
 
WARN [09-16|17:57:47.790] Served trace_block                       conn=100.99.71.158:37410   reqid=0                   t=9.997823596s    err="method handler crashed"

When calling it via

> trace.block('2396379', {"timeout": "240s"})
Error: Post "http://localhost:8545": EOF
	at web3.js:6347:37(47)
	at web3.js:5081:62(37)
	at <eval>:1:12(7)

I set verbosity to 5 and the trace verbosity to 6. Here's more logging from another run that failed https://gist.github.com/afmsavage/1f832167c44011edf0932bc215d5615e

[afmsavage]

I have been following this Issue on the Ethereum Geth repo ethereum/go-ethereum#23552. Similar issue I think.

[ziogaschr]

I think I can handle the panic (thx for the catch), but this will return the actual error and not the trace. Can you share your system stats, I care mostly for the size of your RAM.

[afmsavage]

System has 32GB RAM.
Here is our startup command:

geth --syncmode full --gcmode archive --http --http.addr 0.
0.0.0 --http.corsdomain * --http.api db,eth,net,web3,debug,trace --http.port 854
5 --http.vhosts * --maxpeers 50 --ws --ws.addr 0.0.0.0 --ws.origins * --ws.port
8545 --metrics --pprof --pprof.addr 0.0.0.0 --pprof.port 6060 --datadir /ethereu
m/ --cache 4096 --networkid 1 --classic --verbosity 4 --snapshot=false

I did notice one thing that is similar to an issue we were seeing on a debug.traceBlockByNumber on Ethereum archival for block 13184527 https://etherscan.io/block/13184527. Both of these blocks have a contract creation transaction that failed with Out of Gas. When we output this block to a file, it was like 21GB or something just insanely large.

Ethereum Contract Creation out of gas
Ethereum Classic Creation out of gas

I cannot run a trace.transaction on that specific TX without it timing out in the same way the trace.block does.

> trace.transaction('0xeffd72d2245acd53020c519d2be29bd82f83e184730e3b2dbd0015ea0a425725',{timeout: "120s"})
Error: Post "http://localhost:8545": EOF
	at web3.js:6347:37(47)
	at web3.js:5081:62(37)
	at <eval>:1:18(7)

[ziogaschr]

Thanks @afmsavage. I can't reproduce this one, so I just check the code to find anything that can cause it.

I will update you once I find something that triggers my attention.
We will also try to return better errors.

[afmsavage]

Looks like Geth devs have decided to disable returnData and memory by default in this pR ethereum/go-ethereum#23558

[ziogaschr]

Thanks for sharing this @afmsavage. A nice heads up. Though this has been merged at geth 10 days ago and hasn't reached core-geth yet.

@meowsbits @iquidus: just a heads up

[ziogaschr]

@afmsavage can you please try running the same using #418 and let me know of the error returned?

Thanks