optimism icon indicating copy to clipboard operation
optimism copied to clipboard

OP-node stops syncing l2_finalized blocks

Open AlbertMakhortov opened this issue 1 year ago • 9 comments

Bug Description At some point node just stops updating l2_finalized block (but continuing to sync unsafe l2 blocks) Restart of the node helps, but after the restart node starts walking back process, which can take a lot of time, depending on how long l2 finalized block havent been updated (sometimes week a longer)

Steps to Reproduce There is no steps to reproduce, it just happens randomly on different nodes

Expected behavior l2_finalized blocks are syncing in batches with time interval of 15-25 minutes

Environment Information:

  • Operating System: docker-container
  • Package Version op-node 1.7.3

Configurations: --l1BeaconUrl=http://nimbus:5052 --l1RpcUrl=http://geth:8545 --legacyRpcUrl=http://optimism-mainnet-legacy:8545 --sequencerUrl=https://mainnet-sequencer.optimism.io --l2=ws://localhost:8551 --l2.jwt-secret=secret --network=mainnet --rpc.addr=0.0.0.0 --rpc.port=9545

Logs: Logs and/or error messages that help illustrate the issue.

Additional context Add any other context about the problem here.

AlbertMakhortov avatar Apr 19 '24 11:04 AlbertMakhortov

This impacts us pretty often

avinashbo avatar Apr 20 '24 01:04 avinashbo

Sometimes such logs will be output for a long time, up to 25 minutes, l2_safe is growing continuously, but l2_unsafe is not growing. It seems that the block has stopped synchronizing during this period.

 lvl=info msg="Sync progress" reason="reconciled with L1"

iavl avatar Apr 20 '24 13:04 iavl

Facing the same issue. :(

harshsingh-cs avatar Apr 20 '24 17:04 harshsingh-cs

Could provide more context information? Like Latest/finalized block height or other else.

thinkAfCod avatar Apr 21 '24 10:04 thinkAfCod

Seems like issue was fixed in develop here - https://github.com/ethereum-optimism/optimism/pull/10210

tobidae-cb avatar Apr 21 '24 21:04 tobidae-cb

here's some logs of the node, that have stuck l2_finalized block t=2024-04-22T13:56:55+0000 lvl=info msg="Received signed execution payload from p2p" id=0x1417b3c9a72fa69d0632e5490659af42124c1c8ea8ae93dc01f6d86bc0776492:119097719 peer=16Uiu2HAm7dgsqx3gtF9LKWgp5KzHRMLkRrxDaJi9t6B6yz8jxRtu t=2024-04-22T13:56:55+0000 lvl=info msg="Optimistically queueing unsafe L2 execution payload" id=0x1417b3c9a72fa69d0632e5490659af42124c1c8ea8ae93dc01f6d86bc0776492:119097719 t=2024-04-22T13:56:57+0000 lvl=info msg="loaded new runtime config values!" p2p_seq_address=0xAAAA45d9549EDA09E70937013520214382Ffc4A2 t=2024-04-22T13:56:57+0000 lvl=info msg="Received signed execution payload from p2p" id=0xfc33410978ba6f4a88468cff4a2089c4cb4db19c00d6102ac813601d58913cb8:119097720 peer=16Uiu2HAm7dgsqx3gtF9LKWgp5KzHRMLkRrxDaJi9t6B6yz8jxRtu t=2024-04-22T13:56:58+0000 lvl=info msg="Sync progress" reason="unsafe payload from sequencer" l2_finalized=0xc25065d06789615f3cb4c8f87429853907116425df4c01a543275d7c31de1be0:118603539 l2_safe=0xc25065d06789615f3cb4c8f87429853907116425df4c01a543275d7c31de1be0:118603539 l2_pending_safe=0xc25065d06789615f3cb4c8f87429853907116425df4c01a543275d7c31de1be0:118603539 l2_unsafe=0x1417b3c9a72fa69d0632e5490659af42124c1c8ea8ae93dc01f6d86bc0776492:119097719 l2_time=1713794215 l1_derived=0x4ef3534a7082c857a49f879ccc7857e060735a1af999ec2461d8a6fee75a0944:19629709 t=2024-04-22T13:56:58+0000 lvl=info msg="Optimistically queueing unsafe L2 execution payload" id=0xfc33410978ba6f4a88468cff4a2089c4cb4db19c00d6102ac813601d58913cb8:119097720 t=2024-04-22T13:56:58+0000 lvl=info msg="Sync progress" reason="unsafe payload from sequencer" l2_finalized=0xc25065d06789615f3cb4c8f87429853907116425df4c01a543275d7c31de1be0:118603539 l2_safe=0xc25065d06789615f3cb4c8f87429853907116425df4c01a543275d7c31de1be0:118603539 l2_pending_safe=0xc25065d06789615f3cb4c8f87429853907116425df4c01a543275d7c31de1be0:118603539 l2_unsafe=0xfc33410978ba6f4a88468cff4a2089c4cb4db19c00d6102ac813601d58913cb8:119097720 l2_time=1713794217 l1_derived=0x4ef3534a7082c857a49f879ccc7857e060735a1af999ec2461d8a6fee75a0944:19629709 t=2024-04-22T13:56:58+0000 lvl=warn msg="Derivation process temporary error" attempts=1 err="engine stage failed: temp: failed to fetch blobs: failed to get blob sidecars for L1BlockRef 0x4ef3534a7082c857a49f879ccc7857e060735a1af999ec2461d8a6fee75a0944:19629709: failed to fetch blob sidecars for slot 8831843 block 0x4ef3534a7082c857a49f879ccc7857e060735a1af999ec2461d8a6fee75a0944:19629709: failed request with status 404: {\"code\":404,\"message\":\"Block header/data has not been found\"}" t=2024-04-22T13:56:59+0000 lvl=info msg="disconnected from peer" peer=16Uiu2HAmUXTaL7SCDaD1rT6KM3H9KpChrD12MYpmFbnfdMwsVX4b addr=/ip4/44.202.100.32/tcp/30303 t=2024-04-22T13:56:59+0000 lvl=info msg="Received signed execution payload from p2p" id=0x08ad4918b96953f1341f178d6ff3d8600b32a0fa9010760eda3af38c6c78a10f:119097721 peer=16Uiu2HAm7dgsqx3gtF9LKWgp5KzHRMLkRrxDaJi9t6B6yz8jxRtu t=2024-04-22T13:56:59+0000 lvl=info msg="Optimistically queueing unsafe L2 execution payload" id=0x08ad4918b96953f1341f178d6ff3d8600b32a0fa9010760eda3af38c6c78a10f:119097721 t=2024-04-22T13:57:00+0000 lvl=info msg="Sync progress" reason="unsafe payload from sequencer" l2_finalized=0xc25065d06789615f3cb4c8f87429853907116425df4c01a543275d7c31de1be0:118603539 l2_safe=0xc25065d06789615f3cb4c8f87429853907116425df4c01a543275d7c31de1be0:118603539 l2_pending_safe=0xc25065d06789615f3cb4c8f87429853907116425df4c01a543275d7c31de1be0:118603539 l2_unsafe=0x08ad4918b96953f1341f178d6ff3d8600b32a0fa9010760eda3af38c6c78a10f:119097721 l2_time=1713794219 l1_derived=0x4ef3534a7082c857a49f879ccc7857e060735a1af999ec2461d8a6fee75a0944:19629709 t=2024-04-22T13:57:00+0000 lvl=warn msg="Derivation process temporary error" attempts=1 err="engine stage failed: temp: failed to fetch blobs: failed to get blob sidecars for L1BlockRef 0x4ef3534a7082c857a49f879ccc7857e060735a1af999ec2461d8a6fee75a0944:19629709: failed to fetch blob sidecars for slot 8831843 block 0x4ef3534a7082c857a49f879ccc7857e060735a1af999ec2461d8a6fee75a0944:19629709: failed request with status 404: {\"code\":404,\"message\":\"Block header/data has not been found\"}" t=2024-04-22T13:57:01+0000 lvl=info msg="Received signed execution payload from p2p" id=0x8a378f847b253536af1ee23f851e7d67877712e08b417162478d5573e698dbd8:119097722 peer=16Uiu2HAmQPe92ME4w6THs4ZpfyMRBTCuXPpnPqDgEER4jMyA7bq4 t=2024-04-22T13:57:01+0000 lvl=info msg="Optimistically queueing unsafe L2 execution payload" id=0x8a378f847b253536af1ee23f851e7d67877712e08b417162478d5573e698dbd8:119097722 t=2024-04-22T13:57:03+0000 lvl=info msg="Received signed execution payload from p2p" id=0xe5515988ecc36f482df820be0112c1a9b36506c97a23a38bd08a7778a6aef28f:119097723 peer=16Uiu2HAm7dgsqx3gtF9LKWgp5KzHRMLkRrxDaJi9t6B6yz8jxRtu t=2024-04-22T13:57:03+0000 lvl=info msg="Sync progress" reason="unsafe payload from sequencer" l2_finalized=0xc25065d06789615f3cb4c8f87429853907116425df4c01a543275d7c31de1be0:118603539 l2_safe=0xc25065d06789615f3cb4c8f87429853907116425df4c01a543275d7c31de1be0:118603539 l2_pending_safe=0xc25065d06789615f3cb4c8f87429853907116425df4c01a543275d7c31de1be0:118603539 l2_unsafe=0x8a378f847b253536af1ee23f851e7d67877712e08b417162478d5573e698dbd8:119097722 l2_time=1713794221 l1_derived=0x4ef3534a7082c857a49f879ccc7857e060735a1af999ec2461d8a6fee75a0944:19629709 t=2024-04-22T13:57:03+0000 lvl=info msg="Optimistically queueing unsafe L2 execution payload" id=0xe5515988ecc36f482df820be0112c1a9b36506c97a23a38bd08a7778a6aef28f:119097723 t=2024-04-22T13:57:04+0000 lvl=info msg="Sync progress" reason="unsafe payload from sequencer" l2_finalized=0xc25065d06789615f3cb4c8f87429853907116425df4c01a543275d7c31de1be0:118603539 l2_safe=0xc25065d06789615f3cb4c8f87429853907116425df4c01a543275d7c31de1be0:118603539 l2_pending_safe=0xc25065d06789615f3cb4c8f87429853907116425df4c01a543275d7c31de1be0:118603539 l2_unsafe=0xe5515988ecc36f482df820be0112c1a9b36506c97a23a38bd08a7778a6aef28f:119097723 l2_time=1713794223 l1_derived=0x4ef3534a7082c857a49f879ccc7857e060735a1af999ec2461d8a6fee75a0944:19629709 t=2024-04-22T13:57:04+0000 lvl=warn msg="Derivation process temporary error" attempts=1 err="engine stage failed: temp: failed to fetch blobs: failed to get blob sidecars for L1BlockRef 0x4ef3534a7082c857a49f879ccc7857e060735a1af999ec2461d8a6fee75a0944:19629709: failed to fetch blob sidecars for slot 8831843 block 0x4ef3534a7082c857a49f879ccc7857e060735a1af999ec2461d8a6fee75a0944:19629709: failed request with status 404: {\"code\":404,\"message\":\"Block header/data has not been found\"}" t=2024-04-22T13:57:05+0000 lvl=info msg="Received signed execution payload from p2p" id=0x33efba36ab9f42bfab9b0f35ce5af0e898ac7d4fe669148c4b9c273d9a453a6d:119097724 peer=16Uiu2HAm7dgsqx3gtF9LKWgp5KzHRMLkRrxDaJi9t6B6yz8jxRtu t=2024-04-22T13:57:05+0000 lvl=info msg="Optimistically queueing unsafe L2 execution payload" id=0x33efba36ab9f42bfab9b0f35ce5af0e898ac7d4fe669148c4b9c273d9a453a6d:119097724

118603539 - is 11 days old https://optimistic.etherscan.io/block/118603539

AlbertMakhortov avatar Apr 22 '24 14:04 AlbertMakhortov

The issue failed to fetch blobs: failed to get blob sidecars for L1BlockRef will be fixed in op-node v1.7.4. For the moment you can increase the verifier conf depth to reduce the frequency of this issue. If a node runs into this issue, you will need to restart it until you have upgraded to 1.7.4

trianglesphere avatar Apr 24 '24 21:04 trianglesphere

The issue failed to fetch blobs: failed to get blob sidecars for L1BlockRef will be fixed in op-node v1.7.4. For the moment you can increase the verifier conf depth to reduce the frequency of this issue. If a node runs into this issue, you will need to restart it until you have upgraded to 1.7.4

I still have this problem after upgrading to 1.7.4

COLUD4 avatar Apr 29 '24 09:04 COLUD4

@COLUD4 could you open a new issue with logs + exact versions you are running?

trianglesphere avatar Apr 30 '24 21:04 trianglesphere

Closing due to inactivity

tynes avatar Jun 17 '24 22:06 tynes