From 18383a63b275e456774c2c8e03822c22111dd613 Mon Sep 17 00:00:00 2001 From: Michael Sproul Date: Mon, 1 Aug 2022 07:20:43 +0000 Subject: [PATCH] Tidy eth1/deposit contract logging (#3397) ## Issue Addressed Fixes an issue identified by @remyroy whereby we were logging a recommendation to use `--eth1-endpoints` on merge-ready setups (when the execution layer was out of sync). ## Proposed Changes I took the opportunity to clean up the other eth1-related logs, replacing "eth1" by "deposit contract" or "execution" as appropriate. I've downgraded the severity of the `CRIT` log to `ERRO` and removed most of the recommendation text. The reason being that users lacking an execution endpoint will be informed by the new `WARN Not merge ready` log pre-Bellatrix, or the regular errors from block verification post-Bellatrix. --- beacon_node/client/src/builder.rs | 2 +- beacon_node/client/src/notifier.rs | 4 +- beacon_node/eth1/src/service.rs | 63 +++++++++++++----------------- book/src/faq.md | 6 +-- common/fallback/src/lib.rs | 2 +- 5 files changed, 35 insertions(+), 42 deletions(-) diff --git a/beacon_node/client/src/builder.rs b/beacon_node/client/src/builder.rs index 4de28d836..d4c41244d 100644 --- a/beacon_node/client/src/builder.rs +++ b/beacon_node/client/src/builder.rs @@ -851,7 +851,7 @@ where .runtime_context .as_ref() .ok_or("caching_eth1_backend requires a runtime_context")? - .service_context("eth1_rpc".into()); + .service_context("deposit_contract_rpc".into()); let beacon_chain_builder = self .beacon_chain_builder .ok_or("caching_eth1_backend requires a beacon_chain_builder")?; diff --git a/beacon_node/client/src/notifier.rs b/beacon_node/client/src/notifier.rs index 74947c16f..9f82cd201 100644 --- a/beacon_node/client/src/notifier.rs +++ b/beacon_node/client/src/notifier.rs @@ -441,14 +441,14 @@ fn eth1_logging(beacon_chain: &BeaconChain, log: &Logger warn!( log, - "Syncing eth1 block cache"; + "Syncing deposit contract block cache"; "est_blocks_remaining" => distance, ); } } else { error!( log, - "Unable to determine eth1 sync status"; + "Unable to determine deposit contract sync status"; ); } } diff --git a/beacon_node/eth1/src/service.rs b/beacon_node/eth1/src/service.rs index 6f40015fa..a4d4e5e25 100644 --- a/beacon_node/eth1/src/service.rs +++ b/beacon_node/eth1/src/service.rs @@ -14,7 +14,7 @@ use futures::future::TryFutureExt; use parking_lot::{RwLock, RwLockReadGuard}; use sensitive_url::SensitiveUrl; use serde::{Deserialize, Serialize}; -use slog::{crit, debug, error, info, trace, warn, Logger}; +use slog::{debug, error, info, trace, warn, Logger}; use std::fmt::Debug; use std::future::Future; use std::ops::{Range, RangeInclusive}; @@ -39,8 +39,6 @@ const GET_BLOCK_TIMEOUT_MILLIS: u64 = STANDARD_TIMEOUT_MILLIS; /// Timeout when doing an eth_getLogs to read the deposit contract logs. const GET_DEPOSIT_LOG_TIMEOUT_MILLIS: u64 = 60_000; -const WARNING_MSG: &str = "BLOCK PROPOSALS WILL FAIL WITHOUT VALID, SYNCED ETH1 CONNECTION"; - /// Number of blocks to download if the node detects it is lagging behind due to an inaccurate /// relationship between block-number-based follow distance and time-based follow distance. const CATCHUP_BATCH_SIZE: u64 = 128; @@ -202,7 +200,7 @@ async fn endpoint_state( if chain_id == Eth1Id::Custom(0) { warn!( log, - "Remote eth1 node is not synced"; + "Remote execution node is not synced"; "endpoint" => %endpoint, "action" => "trying fallbacks" ); @@ -211,11 +209,11 @@ async fn endpoint_state( if &chain_id != config_chain_id { warn!( log, - "Invalid eth1 chain id. Please switch to correct chain id on endpoint"; + "Invalid execution chain ID. Please switch to correct chain ID on endpoint"; "endpoint" => %endpoint, "action" => "trying fallbacks", - "expected" => format!("{:?}",config_chain_id), - "received" => format!("{:?}", chain_id), + "expected" => ?config_chain_id, + "received" => ?chain_id, ); Err(EndpointError::WrongChainId) } else { @@ -252,7 +250,7 @@ async fn get_remote_head_and_new_block_ranges( if remote_head_block.timestamp + node_far_behind_seconds < now { warn!( service.log, - "Eth1 endpoint is not synced"; + "Execution endpoint is not synced"; "endpoint" => %endpoint, "last_seen_block_unix_timestamp" => remote_head_block.timestamp, "action" => "trying fallback" @@ -264,7 +262,7 @@ async fn get_remote_head_and_new_block_ranges( if let SingleEndpointError::RemoteNotSynced { .. } = e { warn!( service.log, - "Eth1 endpoint is not synced"; + "Execution endpoint is not synced"; "endpoint" => %endpoint, "action" => "trying fallbacks" ); @@ -749,15 +747,11 @@ impl Service { .iter() .all(|error| matches!(error, SingleEndpointError::EndpointError(_))) { - crit!( + error!( self.log, - "Could not connect to a suitable eth1 node. Please ensure that you have \ - an eth1 http server running locally on http://localhost:8545 or specify \ - one or more (remote) endpoints using \ - `--eth1-endpoints `. \ - Also ensure that `eth` and `net` apis are enabled on the eth1 http \ - server"; - "warning" => WARNING_MSG + "No synced execution endpoint"; + "advice" => "ensure you have an execution node configured via \ + --execution-endpoint or if pre-merge, --eth1-endpoints" ); } } @@ -778,12 +772,7 @@ impl Service { get_remote_head_and_new_block_ranges(e, self, node_far_behind_seconds).await }) .await - .map_err(|e| { - format!( - "Failed to update Eth1 service: {:?}", - process_single_err(&e) - ) - })?; + .map_err(|e| format!("{:?}", process_single_err(&e)))?; if num_errors > 0 { info!(self.log, "Fetched data from fallback"; "fallback_number" => num_errors); @@ -815,16 +804,15 @@ impl Service { deposit_cache.last_processed_block = deposit_cache.cache.latest_block_number(); } - let outcome = outcome_result.map_err(|e| { - format!("Failed to update eth1 deposit cache: {:?}", process_err(e)) - })?; + let outcome = outcome_result + .map_err(|e| format!("Failed to update deposit cache: {:?}", process_err(e)))?; trace!( self.log, - "Updated eth1 deposit cache"; + "Updated deposit cache"; "cached_deposits" => self.inner.deposit_cache.read().cache.len(), "logs_imported" => outcome.logs_imported, - "last_processed_eth1_block" => self.inner.deposit_cache.read().last_processed_block, + "last_processed_execution_block" => self.inner.deposit_cache.read().last_processed_block, ); Ok::<_, String>(outcome) }; @@ -833,11 +821,16 @@ impl Service { let outcome = self .update_block_cache(Some(new_block_numbers_block_cache), &endpoints) .await - .map_err(|e| format!("Failed to update eth1 block cache: {:?}", process_err(e)))?; + .map_err(|e| { + format!( + "Failed to update deposit contract block cache: {:?}", + process_err(e) + ) + })?; trace!( self.log, - "Updated eth1 block cache"; + "Updated deposit contract block cache"; "cached_blocks" => self.inner.block_cache.read().len(), "blocks_imported" => outcome.blocks_imported, "head_block" => outcome.head_block_number, @@ -890,13 +883,13 @@ impl Service { match update_result { Err(e) => error!( self.log, - "Failed to update eth1 cache"; + "Error updating deposit contract cache"; "retry_millis" => update_interval.as_millis(), "error" => e, ), Ok((deposit, block)) => debug!( self.log, - "Updated eth1 cache"; + "Updated deposit contract cache"; "retry_millis" => update_interval.as_millis(), "blocks" => format!("{:?}", block), "deposits" => format!("{:?}", deposit), @@ -1180,7 +1173,7 @@ impl Service { debug!( self.log, - "Downloading eth1 blocks"; + "Downloading execution blocks"; "first" => ?required_block_numbers.first(), "last" => ?required_block_numbers.last(), ); @@ -1243,7 +1236,7 @@ impl Service { if blocks_imported > 0 { debug!( self.log, - "Imported eth1 block(s)"; + "Imported execution block(s)"; "latest_block_age" => latest_block_mins, "latest_block" => block_cache.highest_block_number(), "total_cached_blocks" => block_cache.len(), @@ -1252,7 +1245,7 @@ impl Service { } else { debug!( self.log, - "No new eth1 blocks imported"; + "No new execution blocks imported"; "latest_block" => block_cache.highest_block_number(), "cached_blocks" => block_cache.len(), ); diff --git a/book/src/faq.md b/book/src/faq.md index e14947fb0..6692d6149 100644 --- a/book/src/faq.md +++ b/book/src/faq.md @@ -6,7 +6,7 @@ - [What should I do if I lose my slashing protection database?](#what-should-i-do-if-i-lose-my-slashing-protection-database) - [How do I update lighthouse?](#how-do-i-update-lighthouse) - [I can't compile lighthouse](#i-cant-compile-lighthouse) -- [What is "Syncing eth1 block cache"](#what-is-syncing-eth1-block-cache) +- [What is "Syncing deposit contract block cache"](#what-is-syncing-deposit-contract-block-cache) - [Can I use redundancy in my staking setup?](#can-i-use-redundancy-in-my-staking-setup) - [How can I monitor my validators](#how-can-i-monitor-my-validators) @@ -154,10 +154,10 @@ You will just also need to make sure the code you have checked out is up to date See [here.](./installation-source.md#troubleshooting) -### What is "Syncing eth1 block cache" +### What is "Syncing deposit contract block cache" ``` -Nov 30 21:04:28.268 WARN Syncing eth1 block cache est_blocks_remaining: initializing deposits, service: slot_notifier +Nov 30 21:04:28.268 WARN Syncing deposit contract block cache est_blocks_remaining: initializing deposits, service: slot_notifier ``` This log indicates that your beacon node is downloading blocks and deposits diff --git a/common/fallback/src/lib.rs b/common/fallback/src/lib.rs index d91de09be..70f327d20 100644 --- a/common/fallback/src/lib.rs +++ b/common/fallback/src/lib.rs @@ -45,7 +45,7 @@ impl Fallback { { match error { FallbackError::AllErrored(v) => format!( - "All fallback errored: {}", + "All fallbacks errored: {}", join( zip(self.servers.iter().map(f), v.iter()) .map(|(server, error)| format!("{} => {:?}", server, error)),