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.

Sign up for GitHub

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

Jump to bottom

RPC method debug_traceTransaction crashed: runtime error: invalid memory address or nil pointer dereference #20602

Closed
bianchi2 opened this issue Jan 28, 2020 · 3 comments
Closed

RPC method debug_traceTransaction crashed: runtime error: invalid memory address or nil pointer dereference #20602

bianchi2 opened this issue Jan 28, 2020 · 3 comments
Labels
need:more-information

Comments

@bianchi2
Copy link

I am using blockscout that connects to geth, and there're lots of method handler crashes on geth side.

Get is started with the following arguments:

--datadir=/root/datadir --rpcvhosts=* --rpccorsdomain='*' --networkid=245234 --rpc --rpcaddr="0.0.0.0" --mine --etherbase=$ETHER_BASE --rpcapi db,eth,net,web3,personal,admin,miner,txpool,debug --allow-insecure-unlock --syncmode full --gcmode archive --ws --wsaddr 0.0.0.0 --wsport 8546 --debug

Geth version: latest Docker image
OS & Version: Linux
Commit hash : (if develop)

Backtrace

Lots of those in geth logs:

WARN [01-28|05:33:02.020|rpc/handler.go:300]             Served debug_traceTransaction            conn=172.25.0.4:37269 reqid=1 t=15.81813ms  err="method handler crashed"
WARN [01-28|05:33:02.024|rpc/handler.go:300]             Served debug_traceTransaction            conn=172.25.0.4:37269 reqid=0 t=1.148323ms  err="required historical state unavailable (reexec=128)"
WARN [01-28|05:33:02.030|rpc/handler.go:300]             Served debug_traceTransaction            conn=172.25.0.4:37269 reqid=0 t=1.153855ms  err="required historical state unavailable (reexec=128)"
WARN [01-28|05:33:02.035|rpc/handler.go:300]             Served debug_traceTransaction            conn=172.25.0.4:37269 reqid=0 t=1.352857ms  err="required historical state unavailable (reexec=128)"
WARN [01-28|05:33:02.036|rpc/handler.go:300]             Served debug_traceTransaction            conn=172.25.0.4:59373 reqid=0 t=1.159611ms  err="required historical state unavailable (reexec=128)"
WARN [01-28|05:33:02.040|rpc/handler.go:300]             Served debug_traceTransaction            conn=172.25.0.4:59373 reqid=0 t=1.176443ms  err="required historical state unavailable (reexec=128)"
WARN [01-28|05:33:02.045|rpc/handler.go:300]             Served debug_traceTransaction            conn=172.25.0.4:59373 reqid=0 t=1.133153ms  err="required historical state unavailable (reexec=128)"
WARN [01-28|05:33:02.046|rpc/handler.go:300]             Served debug_traceTransaction            conn=172.25.0.4:37269 reqid=0 t=1.145265ms  err="required historical state unavailable (reexec=128)"
WARN [01-28|05:33:02.047|rpc/handler.go:300]             Served debug_traceTransaction            conn=172.25.0.4:45907 reqid=0 t=1.150089ms  err="required historical state unavailable (reexec=128)"
WARN [01-28|05:33:02.054|rpc/handler.go:300]             Served debug_traceTransaction            conn=172.25.0.4:59373 reqid=0 t=1.149096ms  err="required historical state unavailable (reexec=128)"
WARN [01-28|05:33:02.054|rpc/handler.go:300]             Served debug_traceTransaction            conn=172.25.0.4:45907 reqid=0 t=1.189126ms  err="required historical state unavailable (reexec=128)"
WARN [01-28|05:33:02.056|rpc/handler.go:300]             Served debug_traceTransaction            conn=172.25.0.4:37269 reqid=0 t=1.282066ms  err="required historical state unavailable (reexec=128)"
WARN [01-28|05:33:02.062|rpc/handler.go:300]             Served debug_traceTransaction            conn=172.25.0.4:45907 reqid=0 t=1.166712ms  err="required historical state unavailable (reexec=128)"
WARN [01-28|05:33:02.065|rpc/handler.go:300]             Served debug_traceTransaction            conn=172.25.0.4:59373 reqid=0 t=1.138595ms  err="required historical state unavailable (reexec=128)"
WARN [01-28|05:33:02.068|rpc/handler.go:300]             Served debug_traceTransaction            conn=172.25.0.4:59373 reqid=0 t=1.164136ms  err="required historical state unavailable (reexec=128)"
WARN [01-28|05:33:02.073|rpc/handler.go:300]             Served debug_traceTransaction            conn=172.25.0.4:59373 reqid=0 t=1.108834ms  err="required historical state unavailable (reexec=128)"
ERROR[01-28|05:33:02.074|rpc/service.go:201]             RPC method debug_traceTransaction crashed: runtime error: invalid memory address or nil pointer dereference
goroutine 25952 [running]:
github.com/ethereum/go-ethereum/rpc.(*callback).call.func1(0xc006a36400, 0x16, 0xc008069d28)
	/go-ethereum/rpc/service.go:200 +0xb5
panic(0x10491c0, 0x1c0afc0)
	/usr/local/go/src/runtime/panic.go:679 +0x1b2
github.com/ethereum/go-ethereum/eth/tracers.(*dbWrapper).pushObject.func3(0xc006d4f550, 0x112efc80)
	/go-ethereum/eth/tracers/tracer.go:204 +0xf6
gopkg.in/olebedev/go-duktape%2ev3.goFunctionCall(0x39a70de0, 0x1297d18)
	/go/pkg/mod/gopkg.in/olebedev/go-duktape.v3@v3.0.0-20190213234257-ec84240a7772/duktape.go:156 +0xb7
gopkg.in/olebedev/go-duktape%2ev3._cgoexpwrap_062d6de2de8d_goFunctionCall(0x39a70de0, 0x1)
	_cgo_gotypes.go:3512 +0x2b
gopkg.in/olebedev/go-duktape%2ev3._Cfunc_duk_pcall_prop(0x39a70de0, 0x200000000, 0x0)
	_cgo_gotypes.go:2311 +0x4d
gopkg.in/olebedev/go-duktape%2ev3.(*Context).PcallProp.func1(0xc006bb8a10, 0x0, 0x2, 0x113156a0)
	/go/pkg/mod/gopkg.in/olebedev/go-duktape.v3@v3.0.0-20190213234257-ec84240a7772/api.go:786 +0x76
gopkg.in/olebedev/go-duktape%2ev3.(*Context).PcallProp(0xc006bb8a10, 0x0, 0x2, 0x2)
	/go/pkg/mod/gopkg.in/olebedev/go-duktape.v3@v3.0.0-20190213234257-ec84240a7772/api.go:786 +0x3f
github.com/ethereum/go-ethereum/eth/tracers.(*Tracer).call(0xc01094be40, 0x11c48b7, 0x6, 0xc008062430, 0x2, 0x2, 0x0, 0x0, 0x0, 0x0, ...)
	/go-ethereum/eth/tracers/tracer.go:504 +0x120
github.com/ethereum/go-ethereum/eth/tracers.(*Tracer).GetResult(0xc01094be40, 0x145cf20, 0xc001642c60, 0xc00737b608, 0x0, 0x0)
	/go-ethereum/eth/tracers/tracer.go:632 +0x4d5
github.com/ethereum/go-ethereum/eth.(*PrivateDebugAPI).traceTx(0xc000011f70, 0x14517c0, 0xc007e31d40, 0x145cf20, 0xc001642c60, 0x12957b8, 0x12957c0, 0xc00828e090, 0xfc64b430e018b662, 0x51aa280e72e719c0, ...)
	/go-ethereum/eth/api_tracer.go:776 +0x47d
github.com/ethereum/go-ethereum/eth.(*PrivateDebugAPI).TraceTransaction(0xc000011f70, 0x14517c0, 0xc007e31d40, 0x32bb8c168cf42a4e, 0xbe66c2c66c5a7767, 0x91502fdebdc343d2, 0xe9c027e220f56298, 0xc0082822a0, 0x0, 0x0, ...)
	/go-ethereum/eth/api_tracer.go:719 +0x20e
reflect.Value.call(0xc0004e4700, 0xc0001d5a68, 0x13, 0x11c1d4a, 0x4, 0xc001642b40, 0x4, 0x4, 0xc008069ba0, 0x4601dc, ...)
	/usr/local/go/src/reflect/value.go:460 +0x5f6
reflect.Value.Call(0xc0004e4700, 0xc0001d5a68, 0x13, 0xc001642b40, 0x4, 0x4, 0x2, 0x2, 0x2)
	/usr/local/go/src/reflect/value.go:321 +0xb4
github.com/ethereum/go-ethereum/rpc.(*callback).call(0xc000e6c780, 0x14517c0, 0xc007e31d40, 0xc006a36400, 0x16, 0xc0081fbe30, 0x2, 0x2, 0x0, 0x0, ...)
	/go-ethereum/rpc/service.go:206 +0x2b9
github.com/ethereum/go-ethereum/rpc.(*handler).runMethod(0xc011882900, 0x14517c0, 0xc007e31d40, 0xc0066e19d0, 0xc000e6c780, 0xc0081fbe30, 0x2, 0x2, 0x2)
	/go-ethereum/rpc/handler.go:369 +0x8a
github.com/ethereum/go-ethereum/rpc.(*handler).handleCall(0xc011882900, 0xc007fd8060, 0xc0066e19d0, 0xc008227740)
	/go-ethereum/rpc/handler.go:331 +0x22c
github.com/ethereum/go-ethereum/rpc.(*handler).handleCallMsg(0xc011882900, 0xc007fd8060, 0xc0066e19d0, 0xc0064c0540)
	/go-ethereum/rpc/handler.go:298 +0x1f3
github.com/ethereum/go-ethereum/rpc.(*handler).handleBatch.func2(0xc007fd8060)
	/go-ethereum/rpc/handler.go:119 +0xf3
github.com/ethereum/go-ethereum/rpc.(*handler).startCallProc.func1(0xc011882900, 0xc007e31d00)
	/go-ethereum/rpc/handler.go:226 +0x119
created by github.com/ethereum/go-ethereum/rpc.(*handler).startCallProc
	/go-ethereum/rpc/handler.go:222 +0x66

Blackscout is making requests and fails:

2020-01-28T05:32:28.848 application=indexer fetcher=internal_transaction count=10 error_count=10 [error] failed to fetch internal transactions for blocks: [%{code: -32000, data: %{block_number: 401, transaction_hash: "0xea37d0135e2a5a54ce5cc1d2cf67c6baf9b615c49119953b3e438e75a85ff605", transaction_index: 0}, message: "required historical state unavailable (reexec=128)"}]

Any suggestions on how I can fix it?
@bianchi2 bianchi2 mentioned this issue Jan 28, 2020
Closed
@holiman
Copy link
Contributor

holiman commented Jan 30, 2020

The db is set in CaptureState, so if a tx does not execute any operation (e.g. a plain value transfer), the db is unset, and it panics on line 204, when trying to access the result.

@karalabe
Copy link
Member

Could you share the tracing code? We have a hunch of what might happen (you're accessing the state in result or fault, which I didn't expect).

@no-response
Copy link

no-response bot commented Feb 29, 2020

This issue has been automatically closed because there has been no response to our request for more information from the original author. With only the information that is currently in the issue, we don't have enough information to take action. Please reach out if you have more relevant information or answers to our questions so that we can investigate further.

@no-response no-response bot closed this as completed Feb 29, 2020
@unclezoro unclezoro mentioned this issue Jun 28, 2020
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
need:more-information
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
5 participants
@ligi @karalabe @holiman @adamschmideg @bianchi2