streamingfast / firehose-ethereum

Ethereum on StreamingFast
Apache License 2.0
80 stars 24 forks source link

`unable to decode payload: proto: cannot parse invalid wire-format data` #58

Closed rootwarp closed 1 year ago

rootwarp commented 1 year ago

I tried to sync firehose-polygon but I got unable to decode payload: proto: cannot parse invalid wire-format data error and all clients are crashed.

fireeth version

$  fireeth --version
fireeth version 1.3.7 (Commit 4ffb127, Built 2023-03-20T13:59:22Z)

Polygon Execution Layer version

~$ geth version
Bor
Version: 0.3.7-stable-fh2
Git Commit: e2931fd6b192eac721f8550315168391dd6e4805
Architecture: amd64
Go Version: go1.19.3
Operating System: linux
GOPATH=/usr/local/go
GOROOT=
root@thegraph-mainnet-firehose1-hetzner-fsn1:~#

config

~$ cat firehose-config.yaml
start:
  args:
    - merger
    - firehose
    - reader-node
    - relayer
    - combined-index-builder
  flags:
    data-dir: /mnt/firehose
    log-to-file: false
    metrics-listen-addr: 0.0.0.0:9102

    common-chain-id: "137"
    common-network-id: "137"

    reader-node-path: /usr/local/bin/geth
    reader-node-ipc-path: /mnt/bor/bor.ipc
      # common-merged-blocks-store-url: /mnt/firehose/polygon/merged-blocks

    reader-node-arguments: "--bor-mainnet --ipcpath=/mnt/bor/bor.ipc --datadir=/mnt/bor/data --bor.heimdall=http://127.0.0.1:1317 --http --http.api=eth,net,web3 --http.port=8545 --http.addr=127.0.0.1 --http.vhosts=* --firehose-enabled --port=30303 --cache=2048"
    # reader-node-log-to-zap: false

Error log

2023-04-03T23:57:00.629Z INFO (merger) starting pruning of unused (old) one-block-files {"pruning_distance_to_lib": 100, "time_between_pruning": "1m0s"}
2023-04-03T23:57:00.629Z INFO (reader) creating new command instance and launch read loop {"binary": "/usr/local/bin/geth", "arguments": ["--bor-mainnet", "--ipcpath=/mnt/bor/bor.ipc", "--datadir=/mnt/bor/data", "--bor.heimdall=http://127.0.0.1:1317", "--http", "--http.api=eth,net,web3", "--http.port=8545", "--http.addr=127.0.0.1", "--http.vhosts=*", "--firehose-enabled", "--port=30303", "--cache=2048"]}
2023-04-03T23:57:00.629Z INFO (dgrpc) launching gRPC server {"listen_addr": ":13012"}
2023-04-03T23:57:00.630Z INFO (dgrpc) serving gRPC {"listen_addr": ":13012"}
2023-04-03T23:57:00.630Z INFO (merger) starting pruning of forked files {"pruning_distance_to_lib": 50000, "time_between_pruning": "1m0s"}
2023-04-03T23:57:00.630Z INFO (reader) successfully start service
2023-04-03T23:57:00.630Z INFO (reader) operator ready to receive commands
2023-04-03T23:57:00.630Z INFO (reader) starting consume flow
2023-04-03T23:57:00.630Z INFO (relayer.src.13010) starting block source consumption {"endpoint_url": ":13010"}
2023-04-03T23:57:00.630Z INFO (relayer.src.13010) block stream source reading messages {"endpoint_url": ":13010"}
2023-04-03T23:57:00.630Z INFO (reader.sub.relayer) receive block request {"trace_id": "4f9ecb873b4cfb3b31db2ae3cadf52d6", "request": {"burst":1,"requester":"relayer"}}
2023-04-03T23:57:00.631Z INFO (reader.sub.relayer) sending burst {"busrt_size": 0}
2023-04-03T23:57:00.631Z INFO (reader) subscribed {"new_length": 1, "subscriber": "relayer"}
2023-04-03T23:57:00.642Z INFO (index-builder) index builder running
2023-04-03T23:57:00.642Z INFO (index-builder) processing incoming blocks request {"req_start_block": 24800000, "req_cursor": "", "req_stop_block": 0, "final_blocks_only": true}
2023-04-03T23:57:00.642Z INFO (index-builder) creating new joining source {"cursor": "<nil>", "start_block_num": 24800000}
2023-04-03T23:57:00.663Z INFO (reader) read firehose instrumentation init line {"fh_version": "2.2", "node_variant": "polygon", "node_version": "0.3.7-stable-fh2-e2931fd6"}
2023-04-03T23:57:01.621Z INFO (merger) resetting bundler base block num {"previous_base_block_num": 0, "new_base_block_num": 40894100, "lib": "#40894099 (f6b1d2c12804bf25)"}
2023-04-03T23:57:02.629Z WARN (reader) geth Monitor cannot get info from IPC socket {"error": "dial unix /mnt/bor/bor.ipc: connect: no such file or directory"}
2023-04-03T23:57:02.774Z WARN (reader.geth) enabling snapshot recovery               chainhead=40,692,459 diskbase=40,693,149
2023-04-03T23:57:02.778Z WARN (reader.geth) loaded snapshot journal                  diskroot=5f84ff..9e06b4 diffs=unmatched
2023-04-03T23:57:02.778Z WARN (reader.geth) snapshot is not continuous with chain    snaproot=5f84ff..9e06b4 chainroot=f41ee7..3eaad4
2023-04-03T23:57:02.821Z WARN (reader.geth) old unclean shutdowns found              count=156
2023-04-03T23:57:02.821Z WARN (reader.geth) unclean shutdown detected                booted=2022-03-15T08:27:58+0000 age=1y3w3d
2023-04-03T23:57:02.821Z WARN (reader.geth) unclean shutdown detected                booted=2022-03-15T09:07:12+0000 age=1y3w3d
2023-04-03T23:57:02.821Z WARN (reader.geth) unclean shutdown detected                booted=2022-03-15T09:46:08+0000 age=1y3w3d
2023-04-03T23:57:02.821Z WARN (reader.geth) unclean shutdown detected                booted=2022-03-15T10:25:12+0000 age=1y3w3d
2023-04-03T23:57:02.821Z WARN (reader.geth) unclean shutdown detected                booted=2022-03-15T11:04:57+0000 age=1y3w3d
2023-04-03T23:57:02.821Z WARN (reader.geth) unclean shutdown detected                booted=2022-03-15T11:44:37+0000 age=1y3w3d
2023-04-03T23:57:02.821Z WARN (reader.geth) unclean shutdown detected                booted=2022-03-15T12:43:50+0000 age=1y3w3d
2023-04-03T23:57:02.821Z WARN (reader.geth) unclean shutdown detected                booted=2022-12-10T10:54:49+0000 age=3mo3w3d
2023-04-03T23:57:02.821Z WARN (reader.geth) unclean shutdown detected                booted=2022-12-10T17:02:34+0000 age=3mo3w3d
2023-04-03T23:57:02.821Z WARN (reader.geth) unclean shutdown detected                booted=2023-04-03T17:47:38+0000 age=6h9m24s
2023-04-03T23:57:02.887Z WARN (reader.geth) unable to whitelist checkpoint - first run err="missing checkpoint blocks"
2023-04-03T23:57:08.213Z INFO (index-builder) blocks archive streaming was asked to stop
2023-04-03T23:57:08.213Z INFO (index-builder) index builder exited {"error": "processing of file \"0024802400\" failed: error processing incoming file: failed reading next dbin message: unexpected EOF"}
2023-04-03T23:57:08.213Z ERRO (fireeth)
################################################################
Fatal error in app combined-index-builder:

processing of file "0024802400" failed: error processing incoming file: failed reading next dbin message: unexpected EOF
################################################################
2023-04-03T23:57:08.213Z INFO (fireeth) application combined-index-builder shutdown unexpectedly, quitting
2023-04-03T23:57:08.213Z INFO (fireeth) waiting for all apps termination...
2023-04-03T23:57:08.213Z INFO (firehose) gracefully stopping the gRPC server {"timeout": "1s"}
2023-04-03T23:57:08.213Z INFO (firehose) gRPC server teminated gracefully
2023-04-03T23:57:08.213Z INFO (reader) operator is terminating {"error": "processing of file \"0024802400\" failed: error processing incoming file: failed reading next dbin message: unexpected EOF"}
2023-04-03T23:57:08.213Z INFO (reader) superviser is terminating
2023-04-03T23:57:08.213Z INFO (reader) supervisor received a stop request, terminating node process
2023-04-03T23:57:08.213Z INFO (reader) stopping underlying process
2023-04-03T23:57:08.213Z INFO (dgrpc) forcing gRPC server to stop
2023-04-03T23:57:08.213Z ERRO (reader.geth) ERROR[04-03|23:57:08.213] Failed to journal state snapshot         err="snapshot [0xf41ee783cdbce53430a600c3d6fbaaba90b422785eda463eeb73bc73c83eaad4] missing"
panic: unable to decode block #24802499 (f36a8609a3818244d3ed85061676f0a336dfc8ec0214f5f0bd25d772003902f9) payload (kind: ETH, version: 3, size: 1445841, sha256: eaed3b16e23cc82dca75df9e09d748e66990605d7a4d0ec4c4baabfe03d98ea8): unable to decode payload: proto: cannot parse invalid wire-format data

Payload: 08031220f36a8609a3818244d3ed85061676f0a336dfc8ec0214f5f0bd25d772003902f918c3e9e90b20aeb0072a96050a20cf37e6d4d69d26a4f65199f7650f2415476d37b063c54e4b6ebd4ea346383c1e12201dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d493471a14000000000000000000000000000000000000000022208c2f83ff
...
...
...
goroutine 3034 [running]:
github.com/streamingfast/bstream.(*Block).ToProtocol(0xc00191a180)
        /go/pkg/mod/github.com/streamingfast/bstream@v0.0.2-0.20230228213106-2b6a3160e01e/block.go:246 +0x6c9
github.com/streamingfast/firehose.glob..func1(0x120e286?)
        /go/pkg/mod/github.com/streamingfast/firehose@v0.1.1-0.20230302211622-876ce189e9c4/factory.go:24 +0x19
github.com/streamingfast/bstream.(*FileSource).preprocess(0xc0019c00c0, 0xc00191a180, 0xc00fcd5f80)
        /go/pkg/mod/github.com/streamingfast/bstream@v0.0.2-0.20230228213106-2b6a3160e01e/filesource.go:496 +0x5b
created by github.com/streamingfast/bstream.(*FileSource).streamReader
        /go/pkg/mod/github.com/streamingfast/bstream@v0.0.2-0.20230228213106-2b6a3160e01e/filesource.go:485 +0x68a
maoueh commented 1 year ago

The file is most probably corrupted, if you downloaded it from somewhere, try downloading it again. You can check if a file is correctly decodable by using:

fireeth tools check merged-blocks <path> -r 24924100:24924200 -s

Where <path> is location where merged bundles are located and 24924100:24924200 is the offending range, in your example file in error is 0024802400 so your range should be 24802400:24802500.

Closing as this (for now) is not a firehose bug directly.