[Merge] Optimistic EL verification (#2683)

* Ignore payload errors

* Only return payload handle on valid response

* Push some engine logs down to debug

* Push ee fork choice log to debug

* Push engine call failure to debug

* Push some more errors to debug

* Fix panic at startup

beacon_node/beacon_chain/src/beacon_chain.rs

@@ -3378,7 +3378,7 @@ impl<T: BeaconChainTypes> BeaconChain<T> {
                         )
                         .await
                         {
-                            error!(
+                            debug!(
                                 log,
                                 "Failed to update execution head";
                                 "error" => ?e

beacon_node/beacon_chain/src/block_verification.rs

@@ -55,7 +55,7 @@ use fork_choice::{ForkChoice, ForkChoiceStore};
 use parking_lot::RwLockReadGuard;
 use proto_array::Block as ProtoBlock;
 use safe_arith::ArithError;
-use slog::{debug, error, Logger};
+use slog::{debug, error, info, Logger};
 use slot_clock::SlotClock;
 use ssz::Encode;
 use state_processing::per_block_processing::{is_execution_enabled, is_merge_block};
@@ -1127,7 +1127,15 @@ impl<'a, T: BeaconChainTypes> FullyVerifiedBlock<'a, T> {
             match is_valid_terminal_pow_block {
                 Some(true) => Ok(()),
                 Some(false) => Err(ExecutionPayloadError::InvalidTerminalPoWBlock),
-                None => Err(ExecutionPayloadError::TerminalPoWBlockNotFound),
+                None => {
+                    info!(
+                        chain.log,
+                        "Optimistically accepting terminal block";
+                        "block_hash" => ?execution_payload.parent_hash,
+                        "msg" => "the terminal block/parent was unavailable"
+                    );
+                    Ok(())
+                }
             }?;
         }
 
@@ -1147,21 +1155,34 @@ impl<'a, T: BeaconChainTypes> FullyVerifiedBlock<'a, T> {
                         object_fork: block.message().body().fork_name(),
                     })?;
 
-            let (execute_payload_status, execute_payload_handle) = execution_layer
-                .block_on(|execution_layer| execution_layer.execute_payload(execution_payload))
-                .map_err(ExecutionPayloadError::from)?;
+            let execute_payload_response = execution_layer
+                .block_on(|execution_layer| execution_layer.execute_payload(execution_payload));
 
-            match execute_payload_status {
-                ExecutePayloadResponse::Valid => Ok(()),
-                ExecutePayloadResponse::Invalid => {
-                    Err(ExecutionPayloadError::RejectedByExecutionEngine)
+            match execute_payload_response {
+                Ok((status, handle)) => match status {
+                    ExecutePayloadResponse::Valid => handle,
+                    ExecutePayloadResponse::Invalid => {
+                        return Err(ExecutionPayloadError::RejectedByExecutionEngine.into());
+                    }
+                    ExecutePayloadResponse::Syncing => {
+                        debug!(
+                            chain.log,
+                            "Optimistically accepting payload";
+                            "msg" => "execution engine is syncing"
+                        );
+                        handle
+                    }
+                },
+                Err(e) => {
+                    error!(
+                        chain.log,
+                        "Optimistically accepting payload";
+                        "error" => ?e,
+                        "msg" => "execution engine returned an error"
+                    );
+                    None
                 }
-                ExecutePayloadResponse::Syncing => {
-                    Err(ExecutionPayloadError::ExecutionEngineIsSyncing)
-                }
-            }?;
-
-            Some(execute_payload_handle)
+            }
         } else {
             None
         };

beacon_node/client/src/builder.rs

@@ -665,13 +665,9 @@ where
                 // Issue the head to the execution engine on startup. This ensures it can start
                 // syncing.
                 if head.is_merge_complete {
-                    let result = runtime_context
-                        .executor
-                        .runtime()
-                        .upgrade()
-                        .ok_or_else(|| "Cannot update engine head, shutting down".to_string())?
-                        .block_on(async move {
-                            BeaconChain::<
+                    runtime_context.executor.spawn(
+                        async move {
+                            let result = BeaconChain::<
                                 Witness<TSlotClock, TEth1Backend, TEthSpec, THotStore, TColdStore>,
                             >::update_execution_engine_forkchoice(
                                 inner_execution_layer,
@@ -679,18 +675,20 @@ where
                                 head.finalized_checkpoint.root,
                                 head.block_root,
                             )
-                            .await
-                        });
+                            .await;
 
-                    // No need to exit early if setting the head fails. It will be set again if/when the
-                    // node comes online.
-                    if let Err(e) = result {
-                        warn!(
-                            log,
-                            "Failed to update head on execution engines";
-                            "error" => ?e
-                        );
-                    }
+                            // No need to exit early if setting the head fails. It will be set again if/when the
+                            // node comes online.
+                            if let Err(e) = result {
+                                warn!(
+                                    log,
+                                    "Failed to update head on execution engines";
+                                    "error" => ?e
+                                );
+                            }
+                        },
+                        "el_fork_choice_update",
+                    );
                 }
 
                 // Spawn a routine that tracks the status of the execution engines.

beacon_node/execution_layer/src/engines.rs

@@ -2,7 +2,7 @@
 
 use crate::engine_api::{EngineApi, Error as EngineApiError};
 use futures::future::join_all;
-use slog::{crit, debug, error, info, warn, Logger};
+use slog::{crit, debug, info, warn, Logger};
 use std::future::Future;
 use tokio::sync::RwLock;
 use types::Hash256;
@@ -89,7 +89,7 @@ impl<T: EngineApi> Engines<T> {
                 .forkchoice_updated(head.head_block_hash, head.finalized_block_hash)
                 .await
             {
-                error!(
+                debug!(
                     self.log,
                     "Failed to issue latest head to engine";
                     "error" => ?e,
@@ -225,7 +225,7 @@ impl<T: EngineApi> Engines<T> {
                 match func(engine).await {
                     Ok(result) => return Ok(result),
                     Err(error) => {
-                        error!(
+                        debug!(
                             self.log,
                             "Execution engine call failed";
                             "error" => ?error,
@@ -291,7 +291,7 @@ impl<T: EngineApi> Engines<T> {
             let is_offline = *engine.state.read().await == EngineState::Offline;
             if !is_offline {
                 func(engine).await.map_err(|error| {
-                    error!(
+                    debug!(
                         self.log,
                         "Execution engine call failed";
                         "error" => ?error,

beacon_node/execution_layer/src/lib.rs

@@ -8,7 +8,7 @@ use engine_api::{Error as ApiError, *};
 use engines::{Engine, EngineError, Engines, ForkChoiceHead, Logging};
 use lru::LruCache;
 use sensitive_url::SensitiveUrl;
-use slog::{crit, error, info, Logger};
+use slog::{crit, debug, error, info, Logger};
 use slot_clock::SlotClock;
 use std::future::Future;
 use std::sync::Arc;
@@ -249,7 +249,7 @@ impl ExecutionLayer {
         random: Hash256,
     ) -> Result<PayloadId, Error> {
         let fee_recipient = self.fee_recipient()?;
-        info!(
+        debug!(
             self.log(),
             "Issuing engine_preparePayload";
             "fee_recipient" => ?fee_recipient,
@@ -285,7 +285,7 @@ impl ExecutionLayer {
         random: Hash256,
     ) -> Result<ExecutionPayload<T>, Error> {
         let fee_recipient = self.fee_recipient()?;
-        info!(
+        debug!(
             self.log(),
             "Issuing engine_getPayload";
             "fee_recipient" => ?fee_recipient,
@@ -323,8 +323,8 @@ impl ExecutionLayer {
     pub async fn execute_payload<T: EthSpec>(
         &self,
         execution_payload: &ExecutionPayload<T>,
-    ) -> Result<(ExecutePayloadResponse, ExecutePayloadHandle), Error> {
-        info!(
+    ) -> Result<(ExecutePayloadResponse, Option<ExecutePayloadHandle>), Error> {
+        debug!(
             self.log(),
             "Issuing engine_executePayload";
             "parent_hash" => ?execution_payload.parent_hash,
@@ -358,23 +358,20 @@ impl ExecutionLayer {
             );
         }
 
-        let execute_payload_response = if valid > 0 {
-            ExecutePayloadResponse::Valid
+        if valid > 0 {
+            let handle = ExecutePayloadHandle {
+                block_hash: execution_payload.block_hash,
+                execution_layer: Some(self.clone()),
+                log: self.log().clone(),
+            };
+            Ok((ExecutePayloadResponse::Valid, Some(handle)))
         } else if invalid > 0 {
-            ExecutePayloadResponse::Invalid
+            Ok((ExecutePayloadResponse::Invalid, None))
         } else if syncing > 0 {
-            ExecutePayloadResponse::Syncing
+            Ok((ExecutePayloadResponse::Syncing, None))
         } else {
-            return Err(Error::EngineErrors(errors));
-        };
-
-        let execute_payload_handle = ExecutePayloadHandle {
-            block_hash: execution_payload.block_hash,
-            execution_layer: Some(self.clone()),
-            log: self.log().clone(),
-        };
-
-        Ok((execute_payload_response, execute_payload_handle))
+            Err(Error::EngineErrors(errors))
+        }
     }
 
     /// Maps to the `engine_consensusValidated` JSON-RPC call.
@@ -392,7 +389,7 @@ impl ExecutionLayer {
         block_hash: Hash256,
         status: ConsensusStatus,
     ) -> Result<(), Error> {
-        info!(
+        debug!(
             self.log(),
             "Issuing engine_consensusValidated";
             "status" => ?status,
@@ -430,7 +427,7 @@ impl ExecutionLayer {
         head_block_hash: Hash256,
         finalized_block_hash: Hash256,
     ) -> Result<(), Error> {
-        info!(
+        debug!(
             self.log(),
             "Issuing engine_forkchoiceUpdated";
             "finalized_block_hash" => ?finalized_block_hash,

beacon_node/execution_layer/src/test_utils/mock_execution_layer.rs

@@ -123,11 +123,13 @@ impl<T: EthSpec> MockExecutionLayer<T> {
         assert_eq!(payload.timestamp, timestamp);
         assert_eq!(payload.random, random);
 
-        let (payload_response, mut payload_handle) =
-            self.el.execute_payload(&payload).await.unwrap();
+        let (payload_response, payload_handle) = self.el.execute_payload(&payload).await.unwrap();
         assert_eq!(payload_response, ExecutePayloadResponse::Valid);
 
-        payload_handle.publish_async(ConsensusStatus::Valid).await;
+        payload_handle
+            .unwrap()
+            .publish_async(ConsensusStatus::Valid)
+            .await;
 
         self.el
             .forkchoice_updated(block_hash, Hash256::zero())