testinprod-io / op-erigon

Optimism implementation on the efficiency frontier
https://op-erigon.testinprod.io
GNU Lesser General Public License v3.0
87 stars 15 forks source link

RPC method eth_getTransactionReceipt crashing #222

Closed trader-payne closed 1 month ago

trader-payne commented 1 month ago

System information

Erigon version: erigon version 0.07.1-unstable

OS & Version: Ubuntu 2204

Commit hash: 782c79d601f6f32ecfb7cdf313d3e76e48819e8e

Erigon Command (with flags/config):

ExecStart=/mnt/data/github/erigon-optimism/build/bin/erigon \
        --datadir=/mnt/data/optimism/erigon/datadir \
        --ethash.dagdir=/mnt/data/optimism/erigon/datadir/ethash \
        --authrpc.jwtsecret=/mnt/data/optimism/erigon/jwt.hex \
        --authrpc.port=9662 \
        --http \
        --http.addr=0.0.0.0 \
        --http.port=9657 \
        --http.compression \
        --http.vhosts=* \
        --http.corsdomain=* \
        --http.api=eth,debug,net,trace,web3,erigon \
        --private.api.addr=0.0.0.0:9092 \
        --ws --ws.compression --ws.port=9757 \
        --metrics --metrics.addr=0.0.0.0 --metrics.port=7070 \
        --torrent.download.rate 80mb \
        --rpc.returndata.limit=1000000 \
        --txpool.gossip.disable=true \
        --chain=op-mainnet \
        --db.size.limit=8TB \
        --nodiscover \
        --rollup.sequencerhttp="https://mainnet-sequencer.optimism.io" \
        --rollup.historicalrpc="http://0.0.0.0:9656"

Erigon RPC part crashes with the following:

[EROR] [10-01|11:48:05.821] RPC method eth_getTransactionReceipt crashed: runtime error: invalid memory address or nil pointer dereference
[service.go:219 panic.go:914 panic.go:261 signal_unix.go:861 receipt.go:78 eth_receipts.go:684 value.go:596 value.go:380 service.go:224 handler.go:532 handler.go:482 handler.go:421 handler.go:241 handler.go:334 asm_amd64.s:1650]
[WARN] [10-01|11:48:05.821] [rpc] served                             conn=10.120.10.135:50994 method=eth_getTransactionReceipt reqid=181 t=236.68µs err="method handler crashed"

A restart fixes it until it happens again, seemingly out of nowhere.

Some graphnode subgraphs logs in case it helps: https://paste.gd/4tbTVr5C https://paste.gd/uODWLBGj https://paste.gd/yK4kVkqT https://paste.gd/NZzv2ShQ

mininny commented 1 month ago

@trader-payne Can you please provide a sample rpc request(curl or cast) that we can try to reproduce this behavior? It'd help a lot debugging this :)

trader-payne commented 1 month ago

@mininny unfortunately it happens totally random without clear repro steps. I can give you access to my archive node if that helps in any way

mininny commented 1 month ago

@trader-payne I see, then do you have the eth_getTransactionReceipt RPC running on your service somewhere?

trader-payne commented 1 month ago

@mininny yeah, it's a graph-node (https://github.com/graphprotocol/graph-node) that is syncing subgraphs. It executes that RPC call while ingesting new blocks

EDIT: both erigon & graphnode are running locally but I can give access to either of them if needed.

mininny commented 1 month ago

@trader-payne Just one example of the txHash for the RPC that crashed could be helpful even if it doesn't reproduce again. Also, would you be able to provide more logs around the RPC crash part that I can look at?

trader-payne commented 1 month ago

@mininny I'll share here as soon as it happens again! 🙌🏻

trader-payne commented 1 month ago

Here are more logs from Erigon side:

payne@rpc-optimism-archive-geth ~ ❯ journalctl -fu erigon-optimism.service -o cat -n 100
[INFO] [10-09|19:44:21.534] [updateForkchoice] Fork choice update: flushing in-memory state (built by previous newPayload)
[INFO] [10-09|19:44:21.576] RPC Daemon notified of new headers       from=126452141 to=126452142 amount=1 hash=0x71f0bbcadbda4e19f12dea2f1b6d9c9cbec01519ef86b1ab078207244512f8e2 header sending=17.41µs log sending=360ns
[INFO] [10-09|19:44:21.577] head updated                             hash=0x71f0bbcadbda4e19f12dea2f1b6d9c9cbec01519ef86b1ab078207244512f8e2 number=126452142
[INFO] [10-09|19:44:23.560] [NewPayload] Handling new payload        height=126452143 hash=0xeeee0c414248f780d4421376128426f341b707d94b8a129f4567aa68f65dff2d
[INFO] [10-09|19:44:23.622] [updateForkchoice] Fork choice update: flushing in-memory state (built by previous newPayload)
[INFO] [10-09|19:44:23.665] RPC Daemon notified of new headers       from=126452142 to=126452143 amount=1 hash=0xeeee0c414248f780d4421376128426f341b707d94b8a129f4567aa68f65dff2d header sending=15.929µs log sending=350ns
[INFO] [10-09|19:44:23.665] head updated                             hash=0xeeee0c414248f780d4421376128426f341b707d94b8a129f4567aa68f65dff2d number=126452143
[INFO] [10-09|19:44:25.483] [NewPayload] Handling new payload        height=126452144 hash=0x2aedf57451c4872e0a38c36c3f6be2dcad057aec6df3f38a70d9b7f3fd957ebb
[INFO] [10-09|19:44:25.533] [updateForkchoice] Fork choice update: flushing in-memory state (built by previous newPayload)
[INFO] [10-09|19:44:25.561] RPC Daemon notified of new headers       from=126452143 to=126452144 amount=1 hash=0x2aedf57451c4872e0a38c36c3f6be2dcad057aec6df3f38a70d9b7f3fd957ebb header sending=15.33µs log sending=340ns
[INFO] [10-09|19:44:25.561] head updated                             hash=0x2aedf57451c4872e0a38c36c3f6be2dcad057aec6df3f38a70d9b7f3fd957ebb number=126452144
[INFO] [10-09|19:44:27.743] [NewPayload] Handling new payload        height=126452145 hash=0x0b942752e27448a3075f050df0f753137d3997216a60920409baa61aba45fec8
[INFO] [10-09|19:44:27.774] [updateForkchoice] Fork choice update: flushing in-memory state (built by previous newPayload)
[INFO] [10-09|19:44:27.795] RPC Daemon notified of new headers       from=126452144 to=126452145 amount=1 hash=0x0b942752e27448a3075f050df0f753137d3997216a60920409baa61aba45fec8 header sending=15.189µs log sending=280ns
[INFO] [10-09|19:44:27.795] head updated                             hash=0x0b942752e27448a3075f050df0f753137d3997216a60920409baa61aba45fec8 number=126452145
[INFO] [10-09|19:44:29.287] [NewPayload] Handling new payload        height=126452146 hash=0xc5048679f0f25d94b339cb1d90cf07c8fadf9b570acb63490e5d530d99d5812e
[INFO] [10-09|19:44:29.328] [updateForkchoice] Fork choice update: flushing in-memory state (built by previous newPayload)
[INFO] [10-09|19:44:29.360] RPC Daemon notified of new headers       from=126452145 to=126452146 amount=1 hash=0xc5048679f0f25d94b339cb1d90cf07c8fadf9b570acb63490e5d530d99d5812e header sending=17.55µs log sending=290ns
[INFO] [10-09|19:44:29.360] head updated                             hash=0xc5048679f0f25d94b339cb1d90cf07c8fadf9b570acb63490e5d530d99d5812e number=126452146
[EROR] [10-09|19:44:31.469] RPC method eth_getBlockReceipts crashed: runtime error: invalid memory address or nil pointer dereference
[service.go:219 panic.go:914 panic.go:261 signal_unix.go:861 receipt.go:78 eth_receipts.go:717 value.go:596 value.go:380 service.go:224 handler.go:532 handler.go:482 handler.go:421 handler.go:241 handler.go:334 asm_amd64.s:1650]
[WARN] [10-09|19:44:31.469] [rpc] served                             conn=10.120.10.135:45336 method=eth_getBlockReceipts reqid=305004 t=278.238µs err="method handler crashed"
[INFO] [10-09|19:44:31.484] [NewPayload] Handling new payload        height=126452147 hash=0xde5c04f9b1e3252d2150f9fa3bb8444bc2f05802c5128c345ad735d153c79a7d
[INFO] [10-09|19:44:31.589] [updateForkchoice] Fork choice update: flushing in-memory state (built by previous newPayload)
[INFO] [10-09|19:44:31.671] RPC Daemon notified of new headers       from=126452146 to=126452147 amount=1 hash=0xde5c04f9b1e3252d2150f9fa3bb8444bc2f05802c5128c345ad735d153c79a7d header sending=19.55µs log sending=370ns
[INFO] [10-09|19:44:31.671] head updated                             hash=0xde5c04f9b1e3252d2150f9fa3bb8444bc2f05802c5128c345ad735d153c79a7d number=126452147
[INFO] [10-09|19:44:33.788] [NewPayload] Handling new payload        height=126452148 hash=0xa1611795e1e2b53164588434c9c6cb4d406b3d1425885183a0ff75b391f4b0c0
[INFO] [10-09|19:44:33.813] [updateForkchoice] Fork choice update: flushing in-memory state (built by previous newPayload)
[INFO] [10-09|19:44:33.832] RPC Daemon notified of new headers       from=126452147 to=126452148 amount=1 hash=0xa1611795e1e2b53164588434c9c6cb4d406b3d1425885183a0ff75b391f4b0c0 header sending=13.79µs log sending=280ns
[INFO] [10-09|19:44:33.832] head updated                             hash=0xa1611795e1e2b53164588434c9c6cb4d406b3d1425885183a0ff75b391f4b0c0 number=126452148
[INFO] [10-09|19:44:35.288] [NewPayload] Handling new payload        height=126452149 hash=0xac7eb840c9edda867a1463503e5adf66bef1e8166f9c1fee13111c4ec7451131
[INFO] [10-09|19:44:35.317] [updateForkchoice] Fork choice update: flushing in-memory state (built by previous newPayload)
[INFO] [10-09|19:44:35.342] RPC Daemon notified of new headers       from=126452148 to=126452149 amount=1 hash=0xac7eb840c9edda867a1463503e5adf66bef1e8166f9c1fee13111c4ec7451131 header sending=14.299µs log sending=340ns
[INFO] [10-09|19:44:35.342] head updated                             hash=0xac7eb840c9edda867a1463503e5adf66bef1e8166f9c1fee13111c4ec7451131 number=126452149
[INFO] [10-09|19:44:37.579] [NewPayload] Handling new payload        height=126452150 hash=0xdb381a9e7a0d73e193db8f620d0d6141e0d8818679d47eee098752d352f69196
[INFO] [10-09|19:44:37.726] [updateForkchoice] Fork choice update: flushing in-memory state (built by previous newPayload)
[INFO] [10-09|19:44:37.786] RPC Daemon notified of new headers       from=126452149 to=126452150 amount=1 hash=0xdb381a9e7a0d73e193db8f620d0d6141e0d8818679d47eee098752d352f69196 header sending=38.39µs log sending=650ns
[INFO] [10-09|19:44:37.787] head updated                             hash=0xdb381a9e7a0d73e193db8f620d0d6141e0d8818679d47eee098752d352f69196 number=126452150
[INFO] [10-09|19:44:39.493] [NewPayload] Handling new payload        height=126452151 hash=0xe9b69eb8ed5d921dfad90a78ca1c78959bb13adac5a295186821a71c56b1a32b
[INFO] [10-09|19:44:39.510] [updateForkchoice] Fork choice update: flushing in-memory state (built by previous newPayload)
[INFO] [10-09|19:44:39.522] RPC Daemon notified of new headers       from=126452150 to=126452151 amount=1 hash=0xe9b69eb8ed5d921dfad90a78ca1c78959bb13adac5a295186821a71c56b1a32b header sending=16.44µs log sending=240ns
[INFO] [10-09|19:44:39.522] head updated                             hash=0xe9b69eb8ed5d921dfad90a78ca1c78959bb13adac5a295186821a71c56b1a32b number=126452151
[INFO] [10-09|19:44:41.518] [NewPayload] Handling new payload        height=126452152 hash=0xfff6f7786879f9faa7c7f9011c9780a4883bcb85c92e96f26ffe5ccd7ae16a86
[INFO] [10-09|19:44:41.553] [updateForkchoice] Fork choice update: flushing in-memory state (built by previous newPayload)
[INFO] [10-09|19:44:41.578] RPC Daemon notified of new headers       from=126452151 to=126452152 amount=1 hash=0xfff6f7786879f9faa7c7f9011c9780a4883bcb85c92e96f26ffe5ccd7ae16a86 header sending=13.75µs log sending=280ns
[INFO] [10-09|19:44:41.578] head updated                             hash=0xfff6f7786879f9faa7c7f9011c9780a4883bcb85c92e96f26ffe5ccd7ae16a86 number=126452152
[INFO] [10-09|19:44:43.399] [NewPayload] Handling new payload        height=126452153 hash=0xe022f16b3c6bda6ede1d26ea80190f016e6fc11530bb907007a3a70b650abc47
[INFO] [10-09|19:44:43.431] [updateForkchoice] Fork choice update: flushing in-memory state (built by previous newPayload)
[INFO] [10-09|19:44:43.455] RPC Daemon notified of new headers       from=126452152 to=126452153 amount=1 hash=0xe022f16b3c6bda6ede1d26ea80190f016e6fc11530bb907007a3a70b650abc47 header sending=15.46µs log sending=360ns
[INFO] [10-09|19:44:43.455] head updated                             hash=0xe022f16b3c6bda6ede1d26ea80190f016e6fc11530bb907007a3a70b650abc47 number=126452153
[EROR] [10-09|19:44:45.377] RPC method eth_getBlockReceipts crashed: runtime error: invalid memory address or nil pointer dereference
[service.go:219 panic.go:914 panic.go:261 signal_unix.go:861 receipt.go:78 eth_receipts.go:717 value.go:596 value.go:380 service.go:224 handler.go:532 handler.go:482 handler.go:421 handler.go:241 handler.go:334 asm_amd64.s:1650]
[WARN] [10-09|19:44:45.377] [rpc] served                             conn=10.120.10.135:45336 method=eth_getBlockReceipts reqid=305005 t=249.898µs err="method handler crashed"
[INFO] [10-09|19:44:45.771] [NewPayload] Handling new payload        height=126452154 hash=0x99da48bfa599fb801aaa061f795e360149f4fc2d2c2eaa2bef02374bf42661c3
[INFO] [10-09|19:44:45.891] [updateForkchoice] Fork choice update: flushing in-memory state (built by previous newPayload)
[INFO] [10-09|19:44:45.938] RPC Daemon notified of new headers       from=126452153 to=126452154 amount=1 hash=0x99da48bfa599fb801aaa061f795e360149f4fc2d2c2eaa2bef02374bf42661c3 header sending=13.57µs log sending=280ns
[INFO] [10-09|19:44:45.938] head updated                             hash=0x99da48bfa599fb801aaa061f795e360149f4fc2d2c2eaa2bef02374bf42661c3 number=126452154
[EROR] [10-09|19:44:46.295] RPC method eth_getBlockReceipts crashed: runtime error: invalid memory address or nil pointer dereference
[service.go:219 panic.go:914 panic.go:261 signal_unix.go:861 receipt.go:78 eth_receipts.go:717 value.go:596 value.go:380 service.go:224 handler.go:532 handler.go:482 handler.go:421 handler.go:241 handler.go:334 asm_amd64.s:1650]
[WARN] [10-09|19:44:46.295] [rpc] served                             conn=10.120.10.135:45336 method=eth_getBlockReceipts reqid=305076 t=213.128µs err="method handler crashed"
[EROR] [10-09|19:44:46.297] RPC method eth_getBlockReceipts crashed: runtime error: invalid memory address or nil pointer dereference
[service.go:219 panic.go:914 panic.go:261 signal_unix.go:861 receipt.go:78 eth_receipts.go:717 value.go:596 value.go:380 service.go:224 handler.go:532 handler.go:482 handler.go:421 handler.go:241 handler.go:334 asm_amd64.s:1650]
[WARN] [10-09|19:44:46.297] [rpc] served                             conn=10.120.10.135:45336 method=eth_getBlockReceipts reqid=305077 t=197.208µs err="method handler crashed"
[EROR] [10-09|19:44:46.373] RPC method eth_getBlockReceipts crashed: runtime error: invalid memory address or nil pointer dereference
[service.go:219 panic.go:914 panic.go:261 signal_unix.go:861 receipt.go:78 eth_receipts.go:717 value.go:596 value.go:380 service.go:224 handler.go:532 handler.go:482 handler.go:421 handler.go:241 handler.go:334 asm_amd64.s:1650]
[WARN] [10-09|19:44:46.373] [rpc] served                             conn=10.120.10.135:45336 method=eth_getBlockReceipts reqid=305078 t=256.318µs err="method handler crashed"
[EROR] [10-09|19:44:46.743] RPC method eth_getBlockReceipts crashed: runtime error: invalid memory address or nil pointer dereference
[service.go:219 panic.go:914 panic.go:261 signal_unix.go:861 receipt.go:78 eth_receipts.go:717 value.go:596 value.go:380 service.go:224 handler.go:532 handler.go:482 handler.go:421 handler.go:241 handler.go:334 asm_amd64.s:1650]
[WARN] [10-09|19:44:46.743] [rpc] served                             conn=10.120.10.135:45336 method=eth_getBlockReceipts reqid=305079 t=234.198µs err="method handler crashed"
[INFO] [10-09|19:44:47.587] [NewPayload] Handling new payload        height=126452155 hash=0xd0b324ab9dc9cfda23ef36614de5f216b475b7ea196271e5db4a27fde10127fe
[INFO] [10-09|19:44:47.614] [updateForkchoice] Fork choice update: flushing in-memory state (built by previous newPayload)
[INFO] [10-09|19:44:47.635] RPC Daemon notified of new headers       from=126452154 to=126452155 amount=1 hash=0xd0b324ab9dc9cfda23ef36614de5f216b475b7ea196271e5db4a27fde10127fe header sending=14.31µs log sending=280ns
[INFO] [10-09|19:44:47.635] head updated                             hash=0xd0b324ab9dc9cfda23ef36614de5f216b475b7ea196271e5db4a27fde10127fe number=126452155
[INFO] [10-09|19:44:49.405] [NewPayload] Handling new payload        height=126452156 hash=0x3a4cebb0d6e9856796093126e477eefbcf2a55b3ba021d9e2dfe5bef8de2225c
[INFO] [10-09|19:44:49.443] [updateForkchoice] Fork choice update: flushing in-memory state (built by previous newPayload)
[INFO] [10-09|19:44:49.473] RPC Daemon notified of new headers       from=126452155 to=126452156 amount=1 hash=0x3a4cebb0d6e9856796093126e477eefbcf2a55b3ba021d9e2dfe5bef8de2225c header sending=17.09µs log sending=330ns
[INFO] [10-09|19:44:49.473] head updated                             hash=0x3a4cebb0d6e9856796093126e477eefbcf2a55b3ba021d9e2dfe5bef8de2225c number=126452156
[EROR] [10-09|19:44:49.925] RPC method eth_getBlockReceipts crashed: runtime error: invalid memory address or nil pointer dereference
[service.go:219 panic.go:914 panic.go:261 signal_unix.go:861 receipt.go:78 eth_receipts.go:717 value.go:596 value.go:380 service.go:224 handler.go:532 handler.go:482 handler.go:421 handler.go:241 handler.go:334 asm_amd64.s:1650]
[WARN] [10-09|19:44:49.925] [rpc] served                             conn=10.120.10.135:45336 method=eth_getBlockReceipts reqid=305080 t=302.977µs err="method handler crashed"
[INFO] [10-09|19:44:51.338] [NewPayload] Handling new payload        height=126452157 hash=0x27a83f0fbf3320e39998682f616d37c2a4715d509185b0f60b2cdf236db2af40
[INFO] [10-09|19:44:51.408] [updateForkchoice] Fork choice update: flushing in-memory state (built by previous newPayload)
[INFO] [10-09|19:44:51.449] RPC Daemon notified of new headers       from=126452156 to=126452157 amount=1 hash=0x27a83f0fbf3320e39998682f616d37c2a4715d509185b0f60b2cdf236db2af40 header sending=13.23µs log sending=270ns
[INFO] [10-09|19:44:51.450] head updated                             hash=0x27a83f0fbf3320e39998682f616d37c2a4715d509185b0f60b2cdf236db2af40 number=126452157
[INFO] [10-09|19:44:53.228] [NewPayload] Handling new payload        height=126452158 hash=0x866416cedc86e0bd7f810f08055634330cab4c671ac328216ca82349bd20f457
[INFO] [10-09|19:44:53.265] [updateForkchoice] Fork choice update: flushing in-memory state (built by previous newPayload)
[INFO] [10-09|19:44:53.297] RPC Daemon notified of new headers       from=126452157 to=126452158 amount=1 hash=0x866416cedc86e0bd7f810f08055634330cab4c671ac328216ca82349bd20f457 header sending=16.08µs log sending=270ns
[INFO] [10-09|19:44:53.297] head updated                             hash=0x866416cedc86e0bd7f810f08055634330cab4c671ac328216ca82349bd20f457 number=126452158
[INFO] [10-09|19:44:55.287] [NewPayload] Handling new payload        height=126452159 hash=0x1995b4b387ad6e32209d177f182cea6bc59e2ea150f102d767f1ccb963bca63a
[INFO] [10-09|19:44:55.316] [updateForkchoice] Fork choice update: flushing in-memory state (built by previous newPayload)
[INFO] [10-09|19:44:55.337] RPC Daemon notified of new headers       from=126452158 to=126452159 amount=1 hash=0x1995b4b387ad6e32209d177f182cea6bc59e2ea150f102d767f1ccb963bca63a header sending=12.74µs log sending=330ns
[INFO] [10-09|19:44:55.337] head updated                             hash=0x1995b4b387ad6e32209d177f182cea6bc59e2ea150f102d767f1ccb963bca63a number=126452159
[INFO] [10-09|19:44:57.416] [NewPayload] Handling new payload        height=126452160 hash=0x097dab11d8c3a4c838461b2f5ebbfdb2c9b11f8681d55f6e9b97039c427252d2
[INFO] [10-09|19:44:57.508] [updateForkchoice] Fork choice update: flushing in-memory state (built by previous newPayload)
[INFO] [10-09|19:44:57.555] RPC Daemon notified of new headers       from=126452159 to=126452160 amount=1 hash=0x097dab11d8c3a4c838461b2f5ebbfdb2c9b11f8681d55f6e9b97039c427252d2 header sending=17.779µs log sending=270ns
[INFO] [10-09|19:44:57.555] head updated                             hash=0x097dab11d8c3a4c838461b2f5ebbfdb2c9b11f8681d55f6e9b97039c427252d2 number=126452160
[INFO] [10-09|19:44:59.276] [NewPayload] Handling new payload        height=126452161 hash=0x734555e9e6d73e4930c7dde4a6dc2d490a0341e2ac6735cfca9e7f81bb716f0b
[INFO] [10-09|19:44:59.382] [updateForkchoice] Fork choice update: flushing in-memory state (built by previous newPayload)
[INFO] [10-09|19:44:59.448] RPC Daemon notified of new headers       from=126452160 to=126452161 amount=1 hash=0x734555e9e6d73e4930c7dde4a6dc2d490a0341e2ac6735cfca9e7f81bb716f0b header sending=15.25µs log sending=270ns
[INFO] [10-09|19:44:59.448] head updated                             hash=0x734555e9e6d73e4930c7dde4a6dc2d490a0341e2ac6735cfca9e7f81bb716f0b number=126452161
[INFO] [10-09|19:45:01.274] [NewPayload] Handling new payload        height=126452162 hash=0xd6fca2a0c2d8eaa12be4b3a0dd3c01c3d1f2cb31e2cfe0581eca24cb2c5f08ab
[INFO] [10-09|19:45:01.310] [updateForkchoice] Fork choice update: flushing in-memory state (built by previous newPayload)
[INFO] [10-09|19:45:01.340] RPC Daemon notified of new headers       from=126452161 to=126452162 amount=1 hash=0xd6fca2a0c2d8eaa12be4b3a0dd3c01c3d1f2cb31e2cfe0581eca24cb2c5f08ab header sending=17.289µs log sending=310ns
[INFO] [10-09|19:45:01.340] head updated                             hash=0xd6fca2a0c2d8eaa12be4b3a0dd3c01c3d1f2cb31e2cfe0581eca24cb2c5f08ab number=126452162
[EROR] [10-09|19:45:02.243] RPC method eth_getBlockReceipts crashed: runtime error: invalid memory address or nil pointer dereference
[service.go:219 panic.go:914 panic.go:261 signal_unix.go:861 receipt.go:78 eth_receipts.go:717 value.go:596 value.go:380 service.go:224 handler.go:532 handler.go:482 handler.go:421 handler.go:241 handler.go:334 asm_amd64.s:1650]
[WARN] [10-09|19:45:02.243] [rpc] served                             conn=10.120.10.135:45336 method=eth_getBlockReceipts reqid=305081 t=273.188µs err="method handler crashed"
[INFO] [10-09|19:45:03.294] [NewPayload] Handling new payload        height=126452163 hash=0xdd892cc080e435643170919d37c17c69f982990865a68dfcd2270bf072c0e4c7
[INFO] [10-09|19:45:03.317] [updateForkchoice] Fork choice update: flushing in-memory state (built by previous newPayload)
[INFO] [10-09|19:45:03.334] RPC Daemon notified of new headers       from=126452162 to=126452163 amount=1 hash=0xdd892cc080e435643170919d37c17c69f982990865a68dfcd2270bf072c0e4c7 header sending=16.53µs log sending=300ns
[INFO] [10-09|19:45:03.334] head updated                             hash=0xdd892cc080e435643170919d37c17c69f982990865a68dfcd2270bf072c0e4c7 number=126452163
[INFO] [10-09|19:45:05.288] [NewPayload] Handling new payload        height=126452164 hash=0xfbfee97d15fba5abf633bea7a6deecee3eaf257983ec8c453a987eaa03fb44ff
[INFO] [10-09|19:45:05.329] [updateForkchoice] Fork choice update: flushing in-memory state (built by previous newPayload)
[INFO] [10-09|19:45:05.361] RPC Daemon notified of new headers       from=126452163 to=126452164 amount=1 hash=0xfbfee97d15fba5abf633bea7a6deecee3eaf257983ec8c453a987eaa03fb44ff header sending=17.23µs log sending=270ns
[INFO] [10-09|19:45:05.361] head updated                             hash=0xfbfee97d15fba5abf633bea7a6deecee3eaf257983ec8c453a987eaa03fb44ff number=126452164
[INFO] [10-09|19:45:07.432] [NewPayload] Handling new payload        height=126452165 hash=0xb5d35d8e67202cc07dcf65963a1fe5b0d70f7bf395ec541748cecaa466e68dbe
mininny commented 1 month ago

@trader-payne I'm trying to debug this, but I'm not able to reproduce this on my node with the same RPC and same block number. Can you set the log.console.verbosity=4 and give me the logs again? Could you also provide the op-node startup flags?

mininny commented 1 month ago

@trader-payne I haven't been able to replicate this, so I'm not able to validate the fix, but I have patched something in the code that might be related: https://github.com/testinprod-io/op-erigon/pull/225 Could you try with this branch and see if it fixes the problem? However, I can't guarantee that it will work.

trader-payne commented 1 month ago

Hey @mininny just built that new branch and deployed it to prod. I'll keep an eye out if it happens again, and I'll get more logs for you! Thanks a lot! 🙏🏻

Here are the op-node startup flags:

ExecStart=/mnt/data/github/op-node/op-node/bin/op-node \
                --l1=http://10.120.10.116:9656 \
                --l2=http://0.0.0.0:9662 \
                --network=mainnet \
                --rpc.addr=0.0.0.0 \
                --rpc.port=9545 \
                --l2.jwt-secret=/mnt/data/optimism/erigon/jwt.hex \
                --l1.trustrpc \
                --l1.rpckind=erigon \
                --metrics.enabled \
                --l1.beacon=http://10.120.10.116:5052 \
                --metrics.addr=0.0.0.0 \
                --metrics.port=7071
mininny commented 1 month ago

@trader-payne Thanks! Any progress on the node so far?

trader-payne commented 1 month ago

So far so good, but I'll keep you posted. It happens randomly, but usually 3-4 times a day at the very least.

trader-payne commented 1 month ago

@mininny looks surprisingly solid, thanks for that PR! 🙌🏻 I haven't seen that error occur again.

mininny commented 1 month ago

@trader-payne That's great, then I'll get this code reviewed by the team and have it released within this week :)

trader-payne commented 1 month ago

Thanks a ton @mininny 🙏🏻