New optimism node syncing very slow

[ethereum-optimism]

New optimism node syncing very slow

[opfocus]

CC @sbvegan @Chomtana
t=2024-02-14T12:13:27+0000 lvl=warn msg="Derivation process temporary error" attempts=1 err="engine stage failed: temp: temporarily cannot insert new safe block: failed to create new block via forkchoice: Post \"http://op-geth:8551\": context deadline exceeded"

This seems a bit strange to me, op-geth is still inserting new blocks, this timeout may be sporadic

[darkxeno]

Thanks @opfocus for looking into this.

The timeouts seem to be consistent, like failing some of the first attempts.

This is a filtered output of those, from another node (same config, newer snapshot):

docker logs --since 5m 3e3357211b29 | grep "context deadline exceeded"

t=2024-02-19T10:13:48+0000 lvl=warn msg="Failed to share forkchoice-updated signal" state="&{HeadBlockHash:0xe83e456e05fb25dbe7ab3dce1288cd9b2a072211d56e2f272352f7e2a32e1449 SafeBlockHash:0xe83e456e05fb25dbe7ab3dce1288cd9b2a072211d56e2f272352f7e2a32e1449 FinalizedBlockHash:0x7b213c8fba32473e0199edd8a2a742d8aa455cc612466e4e699ab3cac1848037}" err="Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:13:48+0000 lvl=warn msg="Derivation process temporary error" attempts=1 err="engine stage failed: temp: temporarily cannot insert new safe block: failed to create new block via forkchoice: Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:13:56+0000 lvl=warn msg="Failed to share forkchoice-updated signal" state="&{HeadBlockHash:0x86abb26752255cc9506d62cd8b078be1874a40f5cffb64d44dd75a2919290878 SafeBlockHash:0x86abb26752255cc9506d62cd8b078be1874a40f5cffb64d44dd75a2919290878 FinalizedBlockHash:0x7b213c8fba32473e0199edd8a2a742d8aa455cc612466e4e699ab3cac1848037}" err="Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:13:56+0000 lvl=warn msg="Derivation process temporary error" attempts=1 err="engine stage failed: temp: temporarily cannot insert new safe block: failed to create new block via forkchoice: Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:14:11+0000 lvl=warn msg="Failed to share forkchoice-updated signal" state="&{HeadBlockHash:0xe4cfd5267fc55074216279dc68f68c2d207e991c3de41c225b70c4272f84f2bb SafeBlockHash:0xe4cfd5267fc55074216279dc68f68c2d207e991c3de41c225b70c4272f84f2bb FinalizedBlockHash:0x7b213c8fba32473e0199edd8a2a742d8aa455cc612466e4e699ab3cac1848037}" err="Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:14:11+0000 lvl=warn msg="Derivation process temporary error" attempts=1 err="engine stage failed: temp: temporarily cannot insert new safe block: failed to create new block via forkchoice: Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:14:20+0000 lvl=warn msg="Failed to share forkchoice-updated signal" state="&{HeadBlockHash:0x77191cad5112b7bee2a78077d8d67f2b3f58b992dab27aef1fd9d6321c6d0fd5 SafeBlockHash:0x77191cad5112b7bee2a78077d8d67f2b3f58b992dab27aef1fd9d6321c6d0fd5 FinalizedBlockHash:0x7b213c8fba32473e0199edd8a2a742d8aa455cc612466e4e699ab3cac1848037}" err="Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:14:20+0000 lvl=warn msg="Derivation process temporary error" attempts=1 err="engine stage failed: temp: temporarily cannot insert new safe block: failed to create new block via forkchoice: Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:14:33+0000 lvl=warn msg="Failed to share forkchoice-updated signal" state="&{HeadBlockHash:0xbe30fe05c6c5975c6b3cd1adfea0f893c7b6a1ee88c9e75bd0e9360be5f37f24 SafeBlockHash:0xbe30fe05c6c5975c6b3cd1adfea0f893c7b6a1ee88c9e75bd0e9360be5f37f24 FinalizedBlockHash:0x7b213c8fba32473e0199edd8a2a742d8aa455cc612466e4e699ab3cac1848037}" err="Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:14:33+0000 lvl=warn msg="Derivation process temporary error" attempts=1 err="engine stage failed: temp: temporarily cannot insert new safe block: failed to create new block via forkchoice: Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:14:44+0000 lvl=warn msg="Failed to share forkchoice-updated signal" state="&{HeadBlockHash:0xd3eb3899fd05cb977a5c11a2ed606b93113dce8ca712fb40511e679f2027c3ac SafeBlockHash:0xd3eb3899fd05cb977a5c11a2ed606b93113dce8ca712fb40511e679f2027c3ac FinalizedBlockHash:0x7b213c8fba32473e0199edd8a2a742d8aa455cc612466e4e699ab3cac1848037}" err="Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:14:44+0000 lvl=warn msg="Derivation process temporary error" attempts=1 err="engine stage failed: temp: temporarily cannot insert new safe block: failed to create new block via forkchoice: Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:15:07+0000 lvl=warn msg="Failed to share forkchoice-updated signal" state="&{HeadBlockHash:0xaad0e4670d40df4610694f4c6d61bd7d9a14ea1e6ebb810ffeb64dfd89bf4974 SafeBlockHash:0xaad0e4670d40df4610694f4c6d61bd7d9a14ea1e6ebb810ffeb64dfd89bf4974 FinalizedBlockHash:0x7b213c8fba32473e0199edd8a2a742d8aa455cc612466e4e699ab3cac1848037}" err="Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:15:07+0000 lvl=warn msg="Derivation process temporary error" attempts=1 err="engine stage failed: temp: temporarily cannot insert new safe block: failed to create new block via forkchoice: Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:15:25+0000 lvl=warn msg="Failed to share forkchoice-updated signal" state="&{HeadBlockHash:0xbe54dca23462d05a66d7cb908ce2e6fc9fb86dcf6f774fea6168ed3dcd3118e0 SafeBlockHash:0xbe54dca23462d05a66d7cb908ce2e6fc9fb86dcf6f774fea6168ed3dcd3118e0 FinalizedBlockHash:0x7b213c8fba32473e0199edd8a2a742d8aa455cc612466e4e699ab3cac1848037}" err="Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:15:25+0000 lvl=warn msg="Derivation process temporary error" attempts=1 err="engine stage failed: temp: temporarily cannot insert new safe block: failed to create new block via forkchoice: Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:16:04+0000 lvl=warn msg="Failed to share forkchoice-updated signal" state="&{HeadBlockHash:0x3a7f8f9e7406d40391640f79e630ea29a6a5c896438fc1e1af1eb4288b1bf60f SafeBlockHash:0x3a7f8f9e7406d40391640f79e630ea29a6a5c896438fc1e1af1eb4288b1bf60f FinalizedBlockHash:0x7b213c8fba32473e0199edd8a2a742d8aa455cc612466e4e699ab3cac1848037}" err="Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:16:04+0000 lvl=warn msg="Derivation process temporary error" attempts=1 err="engine stage failed: temp: temporarily cannot insert new safe block: failed to create new block via forkchoice: Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:16:19+0000 lvl=warn msg="Failed to share forkchoice-updated signal" state="&{HeadBlockHash:0x825507290eea505a1d0f4c8e29634e75baeac5ee172f66784fc201534086e9d4 SafeBlockHash:0x825507290eea505a1d0f4c8e29634e75baeac5ee172f66784fc201534086e9d4 FinalizedBlockHash:0x7b213c8fba32473e0199edd8a2a742d8aa455cc612466e4e699ab3cac1848037}" err="Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:16:19+0000 lvl=warn msg="Derivation process temporary error" attempts=1 err="engine stage failed: temp: temporarily cannot insert new safe block: failed to create new block via forkchoice: Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:16:38+0000 lvl=warn msg="Failed to share forkchoice-updated signal" state="&{HeadBlockHash:0x366dcb05a4af546005036c99ae8474463d9128bb1668d8397e03218a467de7d6 SafeBlockHash:0x366dcb05a4af546005036c99ae8474463d9128bb1668d8397e03218a467de7d6 FinalizedBlockHash:0x7b213c8fba32473e0199edd8a2a742d8aa455cc612466e4e699ab3cac1848037}" err="Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:16:38+0000 lvl=warn msg="Derivation process temporary error" attempts=1 err="engine stage failed: temp: temporarily cannot insert new safe block: failed to create new block via forkchoice: Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:17:06+0000 lvl=warn msg="Failed to share forkchoice-updated signal" state="&{HeadBlockHash:0x996e9602326ad213b19be289f9b52fd53367fa69e453ecfef9e6c16c135e09c9 SafeBlockHash:0x996e9602326ad213b19be289f9b52fd53367fa69e453ecfef9e6c16c135e09c9 FinalizedBlockHash:0x7b213c8fba32473e0199edd8a2a742d8aa455cc612466e4e699ab3cac1848037}" err="Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:17:06+0000 lvl=warn msg="Derivation process temporary error" attempts=1 err="engine stage failed: temp: temporarily cannot insert new safe block: failed to create new block via forkchoice: Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:17:13+0000 lvl=warn msg="Failed to share forkchoice-updated signal" state="&{HeadBlockHash:0x996e9602326ad213b19be289f9b52fd53367fa69e453ecfef9e6c16c135e09c9 SafeBlockHash:0x996e9602326ad213b19be289f9b52fd53367fa69e453ecfef9e6c16c135e09c9 FinalizedBlockHash:0x7b213c8fba32473e0199edd8a2a742d8aa455cc612466e4e699ab3cac1848037}" err="Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:17:13+0000 lvl=warn msg="Derivation process temporary error" attempts=2 err="engine stage failed: temp: temporarily cannot insert new safe block: failed to create new block via forkchoice: Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:17:34+0000 lvl=warn msg="Failed to share forkchoice-updated signal" state="&{HeadBlockHash:0x90842a6bf7f6879c55283a213aa7282bdea6981c4b6b94ec0679f54079ba92e4 SafeBlockHash:0x90842a6bf7f6879c55283a213aa7282bdea6981c4b6b94ec0679f54079ba92e4 FinalizedBlockHash:0x7b213c8fba32473e0199edd8a2a742d8aa455cc612466e4e699ab3cac1848037}" err="Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:17:34+0000 lvl=warn msg="Derivation process temporary error" attempts=1 err="engine stage failed: temp: temporarily cannot insert new safe block: failed to create new block via forkchoice: Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:17:41+0000 lvl=warn msg="Failed to share forkchoice-updated signal" state="&{HeadBlockHash:0x484fc938d47fca37a0dee7035a234c73d5cb5ba021b8705cbed5df4e6acb1831 SafeBlockHash:0x484fc938d47fca37a0dee7035a234c73d5cb5ba021b8705cbed5df4e6acb1831 FinalizedBlockHash:0x7b213c8fba32473e0199edd8a2a742d8aa455cc612466e4e699ab3cac1848037}" err="Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:17:41+0000 lvl=warn msg="Derivation process temporary error" attempts=1 err="engine stage failed: temp: temporarily cannot insert new safe block: failed to create new block via forkchoice: Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:17:58+0000 lvl=warn msg="Failed to share forkchoice-updated signal" state="&{HeadBlockHash:0x58f2e025aa0a5e367853ca04892b6387f467afa1ac7504b3d6c7bbef821bcf83 SafeBlockHash:0x58f2e025aa0a5e367853ca04892b6387f467afa1ac7504b3d6c7bbef821bcf83 FinalizedBlockHash:0x7b213c8fba32473e0199edd8a2a742d8aa455cc612466e4e699ab3cac1848037}" err="Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:17:58+0000 lvl=warn msg="Derivation process temporary error" attempts=1 err="engine stage failed: temp: temporarily cannot insert new safe block: failed to create new block via forkchoice: Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:18:05+0000 lvl=warn msg="Failed to share forkchoice-updated signal" state="&{HeadBlockHash:0x7a59330371b1f82f17ceed50f5240f4ccaca48e39941d3d7ee826814b0f29a31 SafeBlockHash:0x7a59330371b1f82f17ceed50f5240f4ccaca48e39941d3d7ee826814b0f29a31 FinalizedBlockHash:0x7b213c8fba32473e0199edd8a2a742d8aa455cc612466e4e699ab3cac1848037}" err="Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:18:05+0000 lvl=warn msg="Derivation process temporary error" attempts=1 err="engine stage failed: temp: temporarily cannot insert new safe block: failed to create new block via forkchoice: Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:18:13+0000 lvl=warn msg="Failed to share forkchoice-updated signal" state="&{HeadBlockHash:0xb285b04ed359d55c921d61b130c0c12def850355b9150e3c4f82df477c10bc7f SafeBlockHash:0xb285b04ed359d55c921d61b130c0c12def850355b9150e3c4f82df477c10bc7f FinalizedBlockHash:0x7b213c8fba32473e0199edd8a2a742d8aa455cc612466e4e699ab3cac1848037}" err="Post \"http://op-geth:8551\": context deadline exceeded"
t=2024-02-19T10:18:13+0000 lvl=warn msg="Derivation process temporary error" attempts=1 err="engine stage failed: temp: temporarily cannot insert new safe block: failed to create new block via forkchoice: Post \"http://op-geth:8551\": context deadline exceeded"

Let me know if i can provide some useful information that could help to triage the source issue.