search

testinprod-io / op-erigon

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

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

Open Igorarg91 opened 1 week ago

Igorarg91 commented 1 week ago

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

op-node container config containers:

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 commented 1 week ago

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 commented 1 week ago

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 commented 3 days ago

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

mininny commented 1 day ago

@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?