Lag between original newHead timestamp and timestamp on my Base node op-erigon client.

[Igorarg91]

Description:
We are facing increased delay up to 17 sec between receiving newHeads and the actual timestamp of each blocks on our Base protocol op-erigon client. What could be the reason and how to decrease this lag?

System information
Network
protocol: base
blockchain-network: mainnet
blockchain-client: op-erigon
blockchain-debug-trace: 'true'
blockchain-mode: archive
op-erigon-image: testinprod/op-erigon:2.60.1-0.6.3-amd64
op-node-image: ghcr.io/base-org/node:v0.9.0

Kubernetes node information
STATUS VERSION OS-IMAGE KERNEL-VERSION CONTAINER
Ready v1.27.9-eks-5e0fdde Amazon Linux 2 5.10.210-201.852.amzn2.x86_64 containerd://1.7.11

kubernetes version
Client Version: v1.27.3
Kustomize Version: v5.0.1
Server Version: v1.27.13-eks-3af4770

op-erigon container config

• name: op-erigon
  image: testinprod/op-erigon:2.60.1-0.6.3-amd64
  command:
• erigon
• '--datadir=/home/node/data'
• '--db.pagesize=4096'
• '--ethash.dagdir=/home/node/data/dag'
• '--db.size.limit=8TB'
• '--chain=base-mainnet'
• '--networkid=8453'
• '--authrpc.jwtsecret=/home/node/jwt-secret.txt'
• '--authrpc.vhosts='
• '--http'
• '--http.addr=0.0.0.0'
• '--http.corsdomain=null'
• '--http.vhosts='
• '--http.api=eth,erigon,net,web3,debug,trace'
• '--ws'
• '--rpc.batch.limit=1000'
• '--rpc.returndata.limit=150000'
• '--rollup.sequencerhttp=https://mainnet-sequencer.base.org/'
• '--rollup.historicalrpc='
• '--rollup.historicalrpctimeout=5s'
• '--rpc.txfeecap=100'
• '--maxpeers=0'
• '--nodiscover'
• '--rollup.disabletxpoolgossip=true'
• '--metrics'
• '--metrics.addr=0.0.0.0'
• '--healthcheck'
• '--private.api.addr=0.0.0.0:9090'
• '--private.api.ratelimit=63744'
• '--db.size.limit=8TB'
• '--rpc.batch.concurrency=4'
• '--db.read.concurrency=4096'
• '--rpc.batch.limit=200'
• '--rpc.returndata.limit=200000'

op-node container config
containers:

• name: op-node
  image: ghcr.io/base-org/node:v0.9.0
  command:
• /app/op-node
• '--network=base-mainnet'

--l1=http://erigon-ethereum-mainnet-xxx.default.svc.cluster.local:8545/

--l1.beacon=http://erigon-ethereum-mainnet-xxx.default.svc.cluster.local:5052/

• '--l2=ws://localhost:8551'
• '--l2.jwt-secret=/home/node/jwt-secret.txt'
• '--rpc.addr=0.0.0.0'
• '--rpc.port=9545'
• '--p2p.priv.path=/home/node/p2p-private-key.txt'
• '--p2p.peerstore.path=memory'
• '--p2p.discovery.path=memory'
• '--metrics.enabled'
• '--l1.trustrpc=true'

Erigon version: ./erigon --version

OS & Version: Windows/Linux/OSX

Commit hash:

Erigon Command (with flags/config):

Consensus Layer:

Consensus Layer Command (with flags/config):

Chain/Network:

Expected behaviour
Lag on NewHeads between original blocks created timestamp and timestamp on our nodes is below 1 second.

Actual behaviour
Sometimes delay reaches up to 17 sec between receiving newHeads and the actual timestamp of each blocks on our Base node.

5 Worst Latencies for Base Node:
Block Number My Timestamp Original Timestamp Delta
2353 16615734 2024-07-03 12:33:52 2024-07-03 15:33:35 17.0
2355 16615735 2024-07-03 12:33:52 2024-07-03 15:33:37 15.0
2356 16615736 2024-07-03 12:33:52 2024-07-03 15:33:39 13.0
2357 16615737 2024-07-03 12:33:52 2024-07-03 15:33:41 11.0
2358 16615738 2024-07-03 12:33:52 2024-07-03 15:33:43 9.0

Steps to reproduce the behaviour
Start a websocket subscription and subscribe to new block headers. We will observe that there is delay in receiving the blocks

[mininny]

Hello @Igorarg91, could you please provide us some logs of erigon and op-node while it's syncing? Also, it'd be good to know the hardware spec of the instance it's running on, specifically the CPU and Disk spec.

[Igorarg91]

op-erigon:

[INFO] [07-09|17:21:23.709] [NewPayload] Handling new payload        height=16878168 hash=0xedc8b2f2fc0927ba552726a874e8913e647e23c0b341a28c626876e6d4b648e7
[INFO] [07-09|17:21:24.246] [updateForkchoice] Fork choice update: flushing in-memory state (built by previous newPayload) 
[INFO] [07-09|17:21:24.644] RPC Daemon notified of new headers       from=16878167 to=16878168 amount=1 hash=0xedc8b2f2fc0927ba552726a874e8913e647e23c0b341a28c626876e6d4b648e7 header sending=41.251µs log sending=320ns
[INFO] [07-09|17:21:24.644] head updated  

op-node:

t=2024-07-09T17:21:24+0000 lvl=info msg="Sync progress" reason="new chain head block" l2_finalized=0x87e05716834a8ccc8b3cf533904ef0c2a69499c8f26fd87fc8d2ba5864172458:16877714 l2_safe=0x8840913e8a3873c0a8ed4268e1fb2c99cab290c2ee1b93b39f1fec9bf76b0025:16878129 l2_pending_safe=0x8840913e8a3873c0a8ed4268e1fb2c99cab290c2ee1b93b39f1fec9bf76b0025:16878129 l2_unsafe=0xedc8b2f2fc0927ba552726a874e8913e647e23c0b341a28c626876e6d4b648e7:16878168 l2_backup_unsafe=0x0000000000000000000000000000000000000000000000000000000000000000:0 l2_time=1720545683
t=2024-07-09T17:21:26+0000 lvl=info msg="Received signed execution payload from p2p" id=0x350ca3d799529d7eb3d9f9381bf318bc49b5adabdd6d496ade2926c331d5bb1f:16878169 peer=16Uiu2HAmKzS6sdAAYQRmKERs9DK7pTPn2E6jD5r4XwECvA4G1cU8
t=2024-07-09T17:21:26+0000 lvl=info msg="Optimistically queueing unsafe L2 execution payload" id=0x350ca3d799529d7eb3d9f9381bf318bc49b5adabdd6d496ade2926c331d5bb1f:16878169
t=2024-07-09T17:21:27+0000 lvl=info msg="Sync progress" reason="new chain head block" l2_finalized=0x87e05716834a8ccc8b3cf533904ef0c2a69499c8f26fd87fc8d2ba5864172458:16877714 l2_safe=0x8840913e8a3873c0a8ed4268e1fb2c99cab290c2ee1b93b39f1fec9bf76b0025:16878129 l2_pending_safe=0x8840913e8a3873c0a8ed4268e1fb2c99cab290c2ee1b93b39f1fec9bf76b0025:16878129 l2_unsafe=0x350ca3d799529d7eb3d9f9381bf318bc49b5adabdd6d496ade2926c331d5bb1f:16878169 l2_backup_unsafe=0x0000000000000000000000000000000000000000000000000000000000000000:0 l2_time=1720545685
t=2024-07-09T17:21:27+0000 lvl=info msg="Advancing bq origin" origin=0xfe5978c90b9928e43d5f4a3cd9c2ce52eeb814ca9aeb607d74222d51d6cf03f6:20270393 originBehind=false
t=2024-07-09T17:21:27+0000 lvl=info msg="created new channel" origin=0xfe5978c90b9928e43d5f4a3cd9c2ce52eeb814ca9aeb607d74222d51d6cf03f6:20270393 channel=3425fbff261637f5a5b6cef263be212a length=130020 frame_number=0 is_last=false
t=2024-07-09T17:21:27+0000 lvl=info msg="Reading channel" channel=3425fbff261637f5a5b6cef263be212a frames=5
t=2024-07-09T17:21:27+0000 lvl=info msg="Received signed execution payload from p2p" id=0x38756b4b80893c981e6d3c3aa666552454f719d445d97d220c4f4aa4009189f7:16878170 peer=16Uiu2HAkvSuDapeM1dqzFi17Nn2aypCkm8g3u9yQXhdu8Uy4Y3uR
t=2024-07-09T17:21:27+0000 lvl=info msg="Found next batch" batch_type=SpanBatch batch_timestamp=1720545607 parent_check=0x8840913e8a3873c0a8ed4268e1fb2c99cab290c2 origin_check=0xa7a092ce3fb0776c3e8b99d5aae63fb722165ea0 start_epoch_number=20270371 end_epoch_number=20270376 block_count=33 compression_algo=zlib
t=2024-07-09T17:21:27+0000 lvl=info msg="generated attributes in payload queue" txs=101 timestamp=1720545607

[Igorarg91]

Hello @mininny, could you tell please, do you have any info? or do you need nay additional info from me?

[mininny]

@Igorarg91 Sorry for getting back late on this. Could you please provide me the details of the hardware spec of the instance? Also, this is continuously happening, right?