Skip to content

Block Producion failure due to java.lang.IllegalStateException: ExecutionPayloadResult hasn't been cached for slot N #10756

@tbenr

Description

@tbenr

This was happening in the context of kurtosis test running modified nodes with "produce late blocks" and "publish payload late" capabilities.

This was happening on one of the modified nodes.
We need analyze the situation to check if it is a condition applicable to a vanilla node too.

2026-05-27 19:45:58.043+0000 | validator-async-7 | INFO  | teku-validator-log | Builder     *** Published execution_payload    Slot: 795, Builder: 18446744073709551615, Block Root: 3ad48da5da272e37c37d05f071323fc99d606beca323ce731e77b3d41c1b7737, 0 (0%) gas, EL block: 217a51b0cb0d4a5349cb4fbb7acfbd8634ab4d78101b6444faafa02b89fded41 (544) 
2026-05-27 19:45:58.043+0000 | beaconchain-async-12 | DEBUG | DataColumnSidecarAvailabilityChecker | Availability check for slot 795 NOT_REQUIRED, kzg commitments empty 
2026-05-27 19:45:58.044+0000 | beaconchain-async-12 | DEBUG | ForkChoice | Data availability check for slot: 795, builder: 18446744073709551615, block_root: 0x3ad48da5da272e37c37d05f071323fc99d606beca323ce731e77b3d41c1b7737 result: DataAndValidationResult{validationResult=NOT_REQUIRED, dataSize=0, cause=Optional.empty} 
2026-05-27 19:45:58.049+0000 | forkChoiceNotifier-async-0 | DEBUG | ForkChoiceNotifierImpl | internalForkChoiceUpdated forkChoiceState ForkChoiceState[headBlock=ForkChoiceNode[blockRoot=0x3ad48da5da272e37c37d05f071323fc99d606beca323ce731e77b3d41c1b7737, payloadStatus=PAYLOAD_STATUS_FULL], headBlockSlot=795, headExecutionBlockNumber=544, headExecutionBlockHash=0x217a51b0cb0d4a5349cb4fbb7acfbd8634ab4d78101b6444faafa02b89fded41, safeExecutionBlockHash=0x935461253619c1b780e63835aad29d708a2cf91855d4e91f9435ba47f6174de2, finalizedExecutionBlockHash=0x1fdb5d4ed1c835b2e90b7378114f4366a533f820fd711c9bcc011b720e09e80c, isHeadOptimistic=false] 
2026-05-27 19:45:58.049+0000 | forkChoiceNotifier-async-0 | DEBUG | ForkChoiceNotifierImpl | internalForkChoiceUpdated skipped ordinary FCU because pinned block production is active for slot 796 
2026-05-27 19:46:01.003+0000 | forkChoiceNotifier-async-0 | DEBUG | ForkChoiceNotifierImpl | onAttestationsDue slot 796 
2026-05-27 19:46:01.004+0000 | TimeTick-1 | INFO  | teku-event-log | Slot Event  *** Slot: 796, Block:                                                        ... empty, Justified: 23, Finalized: 22, Peers: 2 
2026-05-27 19:46:01.039+0000 | validator-async-5 | INFO  | teku-validator-log | Validator   *** Published sync_signature       Count: 96, Slot: 796, Root: 3ad48da5da272e37c37d05f071323fc99d606beca323ce731e77b3d41c1b7737 
2026-05-27 19:46:01.078+0000 | validator-async-11 | INFO  | teku-validator-log | Validator   *** Published attestation          Count: 8, Slot: 796, Root: 3ad48da5da272e37c37d05f071323fc99d606beca323ce731e77b3d41c1b7737 
2026-05-27 19:46:04.029+0000 | validator-async-2 | INFO  | teku-validator-log | Validator   *** Published aggregate            Count: 1, Slot: 796, Root: 3ad48da5da272e37c37d05f071323fc99d606beca323ce731e77b3d41c1b7737 
2026-05-27 19:46:04.054+0000 | validator-async-2 | INFO  | teku-validator-log | Validator   *** Published sync_contribution    Count: 10, Slot: 796, Root: 3ad48da5da272e37c37d05f071323fc99d606beca323ce731e77b3d41c1b7737 
2026-05-27 19:46:07.004+0000 | TimeTick-1 | INFO  | teku-event-log | Slot Payload Event  *** Slot: 796, Execution Block:                                                        ... empty, Peers: 2 
2026-05-27 19:46:07.005+0000 | forkChoiceNotifier-async-0 | DEBUG | ForkChoiceNotifierImpl | onPayloadAttestationsDue slot 796 
2026-05-27 19:46:07.005+0000 | forkChoiceNotifier-async-0 | DEBUG | ForkChoiceNotifierImpl | updatePayloadAttributes blockSlot 797 
2026-05-27 19:46:07.013+0000 | forkChoiceNotifier-async-0 | DEBUG | ForkChoiceUpdateData | send - calling forkChoiceUpdated(ForkChoiceState[headBlock=ForkChoiceNode[blockRoot=0xa127d02d1f3faf1ae6e84976b645e5c1e9c38c5cdffe3be0e5e28d1b37c3537b, payloadStatus=PAYLOAD_STATUS_FULL], headBlockSlot=792, headExecutionBlockNumber=543, headExecutionBlockHash=0x125d40b33a4085c5060e914e60ffc550b46c53c118a355ae593b79a36e703b13, safeExecutionBlockHash=0x935461253619c1b780e63835aad29d708a2cf91855d4e91f9435ba47f6174de2, finalizedExecutionBlockHash=0x1fdb5d4ed1c835b2e90b7378114f4366a533f820fd711c9bcc011b720e09e80c, isHeadOptimistic=false], Optional[PayloadBuildingAttributes[proposerIndex=1147, proposalSlot=797, timestamp=1779911170, prevRandao=0x7a480ed476e0a4544901845f7025c8af12d533eeab0e0be7b34754f980cf1e5c, feeRecipient=0x8943545177806ED17B9F23F0a21ee5948eCaa776, validatorRegistration=Optional.empty, withdrawals=Optional[[]], parentBeaconBlock=ForkChoiceNode[blockRoot=0xa127d02d1f3faf1ae6e84976b645e5c1e9c38c5cdffe3be0e5e28d1b37c3537b, payloadStatus=PAYLOAD_STATUS_FULL]]]) 
2026-05-27 19:46:07.033+0000 | validator-async-3 | INFO  | teku-validator-log | Validator   *** Published payload_attestation  Count: 8, Slot: 796, Root: 3ad48da5da272e37c37d05f071323fc99d606beca323ce731e77b3d41c1b7737 
2026-05-27 19:46:07.036+0000 | beaconchain-async-4 | DEBUG | ForkChoiceUpdateData | send - forkChoiceUpdated returned payload id Optional[0x4790aacab89e6e02] for ForkChoiceState[headBlock=ForkChoiceNode[blockRoot=0xa127d02d1f3faf1ae6e84976b645e5c1e9c38c5cdffe3be0e5e28d1b37c3537b, payloadStatus=PAYLOAD_STATUS_FULL], headBlockSlot=792, headExecutionBlockNumber=543, headExecutionBlockHash=0x125d40b33a4085c5060e914e60ffc550b46c53c118a355ae593b79a36e703b13, safeExecutionBlockHash=0x935461253619c1b780e63835aad29d708a2cf91855d4e91f9435ba47f6174de2, finalizedExecutionBlockHash=0x1fdb5d4ed1c835b2e90b7378114f4366a533f820fd711c9bcc011b720e09e80c, isHeadOptimistic=false], Optional[PayloadBuildingAttributes[proposerIndex=1147, proposalSlot=797, timestamp=1779911170, prevRandao=0x7a480ed476e0a4544901845f7025c8af12d533eeab0e0be7b34754f980cf1e5c, feeRecipient=0x8943545177806ED17B9F23F0a21ee5948eCaa776, validatorRegistration=Optional.empty, withdrawals=Optional[[]], parentBeaconBlock=ForkChoiceNode[blockRoot=0xa127d02d1f3faf1ae6e84976b645e5c1e9c38c5cdffe3be0e5e28d1b37c3537b, payloadStatus=PAYLOAD_STATUS_FULL]]] 
2026-05-27 19:46:09.502+0000 | beaconchain-async-6 | INFO  | ValidatorApiHandler | Preparing block production for slot 797 
2026-05-27 19:46:09.505+0000 | forkchoice-async-0 | INFO  | teku-event-log | Reorg Event *** New Head: 48a922e6b41d655b9bb1d73f84385003e55cad93b5a6482c00df470e27bcb164 (794), Previous Head: 3ad48da5da272e37c37d05f071323fc99d606beca323ce731e77b3d41c1b7737 (795), Common Ancestor: b7cb7e13860fa7545078473b59e47aa48c320c788ce4aae40edc0b9fa002df34 (790) 
2026-05-27 19:46:09.510+0000 | forkChoiceNotifier-async-0 | DEBUG | ForkChoiceNotifierImpl | internalForkChoiceUpdated forkChoiceState ForkChoiceState[headBlock=ForkChoiceNode[blockRoot=0x48a922e6b41d655b9bb1d73f84385003e55cad93b5a6482c00df470e27bcb164, payloadStatus=PAYLOAD_STATUS_FULL], headBlockSlot=794, headExecutionBlockNumber=542, headExecutionBlockHash=0xdfd5d0932d3bf3fba84e1e6d4fd217d90554aeefd441c4a929d8546cb547242b, safeExecutionBlockHash=0x935461253619c1b780e63835aad29d708a2cf91855d4e91f9435ba47f6174de2, finalizedExecutionBlockHash=0x1fdb5d4ed1c835b2e90b7378114f4366a533f820fd711c9bcc011b720e09e80c, isHeadOptimistic=false] 
2026-05-27 19:46:09.510+0000 | forkChoiceNotifier-async-0 | DEBUG | ForkChoiceNotifierImpl | Pinned block production for slot 797 with forkChoiceUpdateData ForkChoiceUpdateData{forkChoiceState=ForkChoiceState[headBlock=ForkChoiceNode[blockRoot=0x48a922e6b41d655b9bb1d73f84385003e55cad93b5a6482c00df470e27bcb164, payloadStatus=PAYLOAD_STATUS_FULL], headBlockSlot=794, headExecutionBlockNumber=542, headExecutionBlockHash=0xdfd5d0932d3bf3fba84e1e6d4fd217d90554aeefd441c4a929d8546cb547242b, safeExecutionBlockHash=0x935461253619c1b780e63835aad29d708a2cf91855d4e91f9435ba47f6174de2, finalizedExecutionBlockHash=0x1fdb5d4ed1c835b2e90b7378114f4366a533f820fd711c9bcc011b720e09e80c, isHeadOptimistic=false], payloadBuildingAttributes=Optional.empty, terminalBlockHash=Optional.empty, executionPayloadContext=tech.pegasys.teku.infrastructure.async.SafeFuture@1cac84e5[Not completed]} 
2026-05-27 19:46:09.515+0000 | forkChoiceNotifier-async-0 | DEBUG | ForkChoiceUpdateData | send - calling forkChoiceUpdated(ForkChoiceState[headBlock=ForkChoiceNode[blockRoot=0x48a922e6b41d655b9bb1d73f84385003e55cad93b5a6482c00df470e27bcb164, payloadStatus=PAYLOAD_STATUS_FULL], headBlockSlot=794, headExecutionBlockNumber=542, headExecutionBlockHash=0xdfd5d0932d3bf3fba84e1e6d4fd217d90554aeefd441c4a929d8546cb547242b, safeExecutionBlockHash=0x935461253619c1b780e63835aad29d708a2cf91855d4e91f9435ba47f6174de2, finalizedExecutionBlockHash=0x1fdb5d4ed1c835b2e90b7378114f4366a533f820fd711c9bcc011b720e09e80c, isHeadOptimistic=false], Optional[PayloadBuildingAttributes[proposerIndex=1147, proposalSlot=797, timestamp=1779911170, prevRandao=0x6d794562a19a1f129fbea7651abbdc0ce3a86735823fd65eebf8a81daaed9cbe, feeRecipient=0x8943545177806ED17B9F23F0a21ee5948eCaa776, validatorRegistration=Optional.empty, withdrawals=Optional[[]], parentBeaconBlock=ForkChoiceNode[blockRoot=0x48a922e6b41d655b9bb1d73f84385003e55cad93b5a6482c00df470e27bcb164, payloadStatus=PAYLOAD_STATUS_FULL]]]) 
2026-05-27 19:46:09.540+0000 | beaconchain-async-0 | DEBUG | ForkChoiceUpdateData | send - forkChoiceUpdated returned payload id Optional[0x55552655ec3b79fe] for ForkChoiceState[headBlock=ForkChoiceNode[blockRoot=0x48a922e6b41d655b9bb1d73f84385003e55cad93b5a6482c00df470e27bcb164, payloadStatus=PAYLOAD_STATUS_FULL], headBlockSlot=794, headExecutionBlockNumber=542, headExecutionBlockHash=0xdfd5d0932d3bf3fba84e1e6d4fd217d90554aeefd441c4a929d8546cb547242b, safeExecutionBlockHash=0x935461253619c1b780e63835aad29d708a2cf91855d4e91f9435ba47f6174de2, finalizedExecutionBlockHash=0x1fdb5d4ed1c835b2e90b7378114f4366a533f820fd711c9bcc011b720e09e80c, isHeadOptimistic=false], Optional[PayloadBuildingAttributes[proposerIndex=1147, proposalSlot=797, timestamp=1779911170, prevRandao=0x6d794562a19a1f129fbea7651abbdc0ce3a86735823fd65eebf8a81daaed9cbe, feeRecipient=0x8943545177806ED17B9F23F0a21ee5948eCaa776, validatorRegistration=Optional.empty, withdrawals=Optional[[]], parentBeaconBlock=ForkChoiceNode[blockRoot=0x48a922e6b41d655b9bb1d73f84385003e55cad93b5a6482c00df470e27bcb164, payloadStatus=PAYLOAD_STATUS_FULL]]] 
2026-05-27 19:46:10.002+0000 | ValidatorApiChannel-1 | INFO  | ValidatorApiHandler | delaying block production for slot 797 by 3000 millis 
2026-05-27 19:46:10.003+0000 | ValidatorApiChannel-1 | INFO  | ValidatorApiHandler | Creating unsigned block for slot 797 
2026-05-27 19:46:10.004+0000 | forkChoiceNotifier-async-0 | DEBUG | ForkChoiceNotifierImpl | internalGetPayloadId parentBeaconBlock ForkChoiceNode[blockRoot=0x48a922e6b41d655b9bb1d73f84385003e55cad93b5a6482c00df470e27bcb164, payloadStatus=PAYLOAD_STATUS_FULL] blockSlot 797 
2026-05-27 19:46:10.044+0000 | beaconchain-async-10 | INFO  | DefaultExecutionPayloadBidManager | Considering self-built bid (value: 0.000000 ETH, EL block: 3762c2..8d59) for block at slot 797 
2026-05-27 19:46:11.508+0000 | validator-async-4 | INFO  | BlockProductionDuty | Validator client received block for slot 796, block rewards 0.005335 ETH, execution payload value 0.000000 ETH 
2026-05-27 19:46:11.515+0000 | ValidatorApiChannel-2 | INFO  | ValidatorApiHandler | starting to publish block at slot 796 
2026-05-27 19:46:11.529+0000 | beaconchain-async-5 | DEBUG | ForkChoice | Data availability check for slot: 796, block_root: 0x305c9d4135c0f9b0836fb6c5f47539f92fda169459f2c77d040f6232934ea367 result: DataAndValidationResult{validationResult=NOT_REQUIRED, dataSize=0, cause=Optional.empty} 
2026-05-27 19:46:11.530+0000 | forkchoice-async-0 | DEBUG | BlockImporter | Successfully imported block 305c9d4135c0f9b0836fb6c5f47539f92fda169459f2c77d040f6232934ea367 (796) 
2026-05-27 19:46:11.530+0000 | forkchoice-async-0 | WARN  | teku-event-log | Slow Block Publishing *** Slot: 796 start 13515ms, block_publishing_initiated +3ms, block_import_completed +12ms, complete +0ms total: 15ms 
2026-05-27 19:46:11.531+0000 | validator-async-2 | INFO  | teku-validator-log | Validator   *** Published block                Count: 1, Slot: 796, Root: 305c9d4135c0f9b0836fb6c5f47539f92fda169459f2c77d040f6232934ea367, Blobs: 0, Builder: 18446744073709551615, Bid gas limit: 200000000, Bid EL block: dd4506..3373 
2026-05-27 19:46:11.531+0000 | ValidatorApiChannel-8 | INFO  | ValidatorApiHandler | Producing unsigned execution payload for slot 796 and block 0x48a922e6b41d655b9bb1d73f84385003e55cad93b5a6482c00df470e27bcb164 
2026-05-27 19:46:11.531+0000 | validator-async-12 | ERROR | teku-validator-log | Builder     *** Failed to produce execution_payload  Slot: 796 Builder: 18446744073709551615 java.util.concurrent.CompletionException: java.lang.IllegalStateException: ExecutionPayloadResult hasn't been cached for slot 794
	at java.base/java.util.concurrent.CompletableFuture.wrapInCompletionException(Unknown Source)
	at java.base/java.util.concurrent.CompletableFuture.encodeThrowable(Unknown Source)
	at java.base/java.util.concurrent.CompletableFuture.uniComposeStage(Unknown Source)
	at java.base/java.util.concurrent.CompletableFuture.thenCompose(Unknown Source)
	at tech.pegasys.teku.infrastructure.async.SafeFuture.thenCompose(SafeFuture.java:684)
	at tech.pegasys.teku.validator.coordinator.ValidatorApiHandler.createUnsignedExecutionPayload(ValidatorApiHandler.java:1049)
	at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(Unknown Source)
	at java.base/java.lang.reflect.Method.invoke(Unknown Source)
	at tech.pegasys.teku.infrastructure.events.DirectEventDeliverer.executeMethod(DirectEventDeliverer.java:74)
	at tech.pegasys.teku.infrastructure.events.DirectEventDeliverer.deliverToWithResponse(DirectEventDeliverer.java:67)
	at tech.pegasys.teku.infrastructure.events.AsyncEventDeliverer.lambda$deliverToWithResponse$0(AsyncEventDeliverer.java:83)
	at tech.pegasys.teku.infrastructure.events.AsyncEventDeliverer$QueueReader.deliverNextEvent(AsyncEventDeliverer.java:140)
	at tech.pegasys.teku.infrastructure.events.AsyncEventDeliverer$QueueReader.run(AsyncEventDeliverer.java:131)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at java.base/java.lang.Thread.run(Unknown Source)
Caused by: java.lang.IllegalStateException: ExecutionPayloadResult hasn't been cached for slot 794
	at tech.pegasys.teku.validator.coordinator.ExecutionPayloadFactoryGloas.lambda$getCachedGetPayloadResponseFuture$0(ExecutionPayloadFactoryGloas.java:103)
	at java.base/java.util.Optional.orElseThrow(Unknown Source)
	at tech.pegasys.teku.validator.coordinator.ExecutionPayloadFactoryGloas.getCachedGetPayloadResponseFuture(ExecutionPayloadFactoryGloas.java:101)
	at tech.pegasys.teku.validator.coordinator.ExecutionPayloadFactoryGloas.createUnsignedExecutionPayload(ExecutionPayloadFactoryGloas.java:55)
	at tech.pegasys.teku.validator.coordinator.ValidatorApiHandler.lambda$createUnsignedExecutionPayload$0(ValidatorApiHandler.java:1067)
	... 14 more

2026-05-27 19:46:13.003+0000 | TimeTick-1 | INFO  | teku-event-log | Slot Event  *** Slot: 797, Block:                                                        ... empty, Justified: 23, Finalized: 22, Peers: 2 
2026-05-27 19:46:13.003+0000 | forkChoiceNotifier-async-0 | DEBUG | ForkChoiceNotifierImpl | onAttestationsDue slot 797 
2026-05-27 19:46:13.016+0000 | validator-async-8 | INFO  | BlockProductionDuty | Validator client received block for slot 797, block rewards 0.005061 ETH, execution payload value 0.000000 ETH 
2026-05-27 19:46:13.027+0000 | ValidatorApiChannel-7 | INFO  | ValidatorApiHandler | starting to publish block at slot 797 
2026-05-27 19:46:13.071+0000 | beaconchain-async-9 | DEBUG | ForkChoice | Data availability check for slot: 797, block_root: 0x2de06d1e523e470c9fa8ff844648bef7726e55e27e6048d0a8cf6be6eb36d9c7 result: DataAndValidationResult{validationResult=NOT_REQUIRED, dataSize=0, cause=Optional.empty} 
2026-05-27 19:46:13.073+0000 | forkchoice-async-0 | DEBUG | BlockImporter | Successfully imported block 2de06d1e523e470c9fa8ff844648bef7726e55e27e6048d0a8cf6be6eb36d9c7 (797) 
2026-05-27 19:46:13.073+0000 | forkchoice-async-0 | WARN  | teku-event-log | Slow Block Publishing *** Slot: 797 start 3027ms, block_publishing_initiated +4ms, block_import_completed +42ms, complete +0ms total: 46ms 
2026-05-27 19:46:13.074+0000 | validator-async-6 | INFO  | teku-validator-log | Validator   *** Published block                Count: 1, Slot: 797, Root: 2de06d1e523e470c9fa8ff844648bef7726e55e27e6048d0a8cf6be6eb36d9c7, Blobs: 0, Builder: 18446744073709551615, Bid gas limit: 200000000, Bid EL block: 3762c2..8d59 
2026-05-27 19:46:13.074+0000 | ValidatorApiChannel-3 | INFO  | ValidatorApiHandler | Producing unsigned execution payload for slot 797 and block 0x2de06d1e523e470c9fa8ff844648bef7726e55e27e6048d0a8cf6be6eb36d9c7 
2026-05-27 19:46:13.082+0000 | beaconchain-async-7 | DEBUG | DataColumnSidecarAvailabilityChecker | Starting data availability check for slot 797 
2026-05-27 19:46:13.082+0000 | validator-async-15 | INFO  | teku-validator-log | Builder     *** Published execution_payload    Slot: 797, Builder: 18446744073709551615, Block Root: 2de06d1e523e470c9fa8ff844648bef7726e55e27e6048d0a8cf6be6eb36d9c7, 0 (0%) gas, EL block: 3762c256794843d77a969208008768156df808f195cb3da0550e632954858d59 (543) 
2026-05-27 19:46:13.083+0000 | validator-async-7 | INFO  | teku-validator-log | Validator   *** Published sync_signature       Count: 96, Slot: 797, Root: 48a922e6b41d655b9bb1d73f84385003e55cad93b5a6482c00df470e27bcb164 
2026-05-27 19:46:13.083+0000 | beaconchain-async-7 | DEBUG | DataColumnSidecarAvailabilityChecker | Availability check for slot 797 NOT_REQUIRED, kzg commitments empty 

Metadata

Metadata

Assignees

No one assigned

    Type

    No type
    No fields configured for issues without a type.

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions