From 088cac80202ae5c3f460af1416d5126caf2713cc Mon Sep 17 00:00:00 2001 From: David Palm Date: Wed, 26 Jun 2019 17:46:28 +0200 Subject: [PATCH 01/20] Better logging when backfilling ancient blocks fail Print total blocks imported, closes #10792 --- ethcore/src/snapshot/service.rs | 14 +++++++++++--- ethcore/types/src/restoration_status.rs | 4 ++++ parity/informant.rs | 5 +++-- 3 files changed, 18 insertions(+), 5 deletions(-) diff --git a/ethcore/src/snapshot/service.rs b/ethcore/src/snapshot/service.rs index a9ff866ebed..9d9b772229e 100644 --- a/ethcore/src/snapshot/service.rs +++ b/ethcore/src/snapshot/service.rs @@ -193,6 +193,7 @@ impl Restoration { } self.guard.disarm(); + trace!(target: "snapshot", "restoration finalised correctly"); Ok(()) } @@ -398,7 +399,10 @@ impl Service { return Ok(count); } - let block = self.client.block(BlockId::Hash(parent_hash)).ok_or(::snapshot::error::Error::UnlinkedAncientBlockChain)?; + let block = self.client.block(BlockId::Hash(parent_hash)).ok_or_else(|| { + error!(target: "snapshot", "migrate_blocks: did not find block from parent_hash={} (start_hash={})", parent_hash, start_hash); + ::snapshot::error::Error::UnlinkedAncientBlockChain + })?; parent_hash = block.parent_hash(); let block_number = block.number(); @@ -435,6 +439,7 @@ impl Service { // We couldn't reach the targeted hash if parent_hash != target_hash { + error!(target: "snapshot", "migrate_blocks: could not reach the target_hash, parent_hash={:?}, target_hash={:?}, start_hash={:?}", parent_hash, target_hash, start_hash); return Err(::snapshot::error::Error::UnlinkedAncientBlockChain.into()); } @@ -549,6 +554,8 @@ impl Service { *self.status.lock() = RestorationStatus::Initializing { chunks_done: 0, + state_chunks: manifest.state_hashes.len() as u32, + block_chunks: manifest.block_hashes.len() as u32, }; fs::create_dir_all(&rest_dir)?; @@ -563,7 +570,7 @@ impl Service { manifest: manifest.clone(), pruning: self.pruning, db: self.restoration_db_handler.open(&rest_db)?, - writer: writer, + writer, genesis: &self.genesis_block, guard: Guard::new(rest_db), engine: &*self.engine, @@ -695,6 +702,7 @@ impl Service { Ok(()) | Err(Error::Snapshot(SnapshotError::RestorationAborted)) => (), Err(e) => { + // TODO: after this we're sometimes deadlocked warn!("Encountered error during snapshot restoration: {}", e); *self.restoration.lock() = None; *self.status.lock() = RestorationStatus::Failed; @@ -803,7 +811,7 @@ impl SnapshotService for Service { let mut cur_status = self.status.lock(); match *cur_status { - RestorationStatus::Initializing { ref mut chunks_done } => { + RestorationStatus::Initializing { ref mut chunks_done, .. } => { *chunks_done = self.state_chunks.load(Ordering::SeqCst) as u32 + self.block_chunks.load(Ordering::SeqCst) as u32; } diff --git a/ethcore/types/src/restoration_status.rs b/ethcore/types/src/restoration_status.rs index b36ec7ef4a9..d924a46460e 100644 --- a/ethcore/types/src/restoration_status.rs +++ b/ethcore/types/src/restoration_status.rs @@ -23,6 +23,10 @@ pub enum RestorationStatus { Inactive, /// Restoration is initializing Initializing { + /// Total number of state chunks. + state_chunks: u32, + /// Total number of block chunks. + block_chunks: u32, /// Number of chunks done/imported chunks_done: u32, }, diff --git a/parity/informant.rs b/parity/informant.rs index 2855579762c..b10a54f93f2 100644 --- a/parity/informant.rs +++ b/parity/informant.rs @@ -319,8 +319,9 @@ impl Informant { RestorationStatus::Ongoing { state_chunks, block_chunks, state_chunks_done, block_chunks_done } => { format!("Syncing snapshot {}/{}", state_chunks_done + block_chunks_done, state_chunks + block_chunks) }, - RestorationStatus::Initializing { chunks_done } => { - format!("Snapshot initializing ({} chunks restored)", chunks_done) + RestorationStatus::Initializing { chunks_done, state_chunks, block_chunks } => { + let total_chunks = state_chunks + block_chunks; + format!("Snapshot initializing ({}/{} chunks restored, {:.0}%)", chunks_done, total_chunks, (chunks_done as f32 / total_chunks as f32) * 100.0) }, _ => String::new(), } From 3c13109810739f0bf91eeb61385dbffb5a24fa00 Mon Sep 17 00:00:00 2001 From: David Palm Date: Wed, 26 Jun 2019 18:33:19 +0200 Subject: [PATCH 02/20] `finalize()` doesn't need Engine Pull out call to migrated_blocks() from replace_client_db() --- ethcore/src/snapshot/consensus/authority.rs | 2 +- ethcore/src/snapshot/consensus/mod.rs | 2 +- ethcore/src/snapshot/consensus/work.rs | 2 +- ethcore/src/snapshot/service.rs | 23 ++++++++++----------- 4 files changed, 14 insertions(+), 15 deletions(-) diff --git a/ethcore/src/snapshot/consensus/authority.rs b/ethcore/src/snapshot/consensus/authority.rs index 621d9845121..7ac5e73d854 100644 --- a/ethcore/src/snapshot/consensus/authority.rs +++ b/ethcore/src/snapshot/consensus/authority.rs @@ -348,7 +348,7 @@ impl Rebuilder for ChunkRebuilder { Ok(()) } - fn finalize(&mut self, _engine: &dyn EthEngine) -> Result<(), ::error::Error> { + fn finalize(&mut self) -> Result<(), ::error::Error> { if !self.had_genesis { return Err(Error::WrongChunkFormat("No genesis transition included.".into()).into()); } diff --git a/ethcore/src/snapshot/consensus/mod.rs b/ethcore/src/snapshot/consensus/mod.rs index 670700c10cf..9170a919588 100644 --- a/ethcore/src/snapshot/consensus/mod.rs +++ b/ethcore/src/snapshot/consensus/mod.rs @@ -92,5 +92,5 @@ pub trait Rebuilder: Send { /// /// This should apply the necessary "glue" between chunks, /// and verify against the restored state. - fn finalize(&mut self, engine: &dyn EthEngine) -> Result<(), ::error::Error>; + fn finalize(&mut self) -> Result<(), ::error::Error>; } diff --git a/ethcore/src/snapshot/consensus/work.rs b/ethcore/src/snapshot/consensus/work.rs index 201d528d140..313e5650a94 100644 --- a/ethcore/src/snapshot/consensus/work.rs +++ b/ethcore/src/snapshot/consensus/work.rs @@ -298,7 +298,7 @@ impl Rebuilder for PowRebuilder { } /// Glue together any disconnected chunks and check that the chain is complete. - fn finalize(&mut self, _: &dyn EthEngine) -> Result<(), ::error::Error> { + fn finalize(&mut self) -> Result<(), ::error::Error> { let mut batch = self.db.transaction(); for (first_num, first_hash) in self.disconnected.drain(..) { diff --git a/ethcore/src/snapshot/service.rs b/ethcore/src/snapshot/service.rs index 9d9b772229e..9130e416bf5 100644 --- a/ethcore/src/snapshot/service.rs +++ b/ethcore/src/snapshot/service.rs @@ -110,17 +110,17 @@ impl Restoration { let secondary = components.rebuilder(chain, raw_db.clone(), &manifest)?; - let root = manifest.state_root.clone(); + let final_state_root = manifest.state_root.clone(); Ok(Restoration { - manifest: manifest, + manifest, state_chunks_left: state_chunks, block_chunks_left: block_chunks, state: StateRebuilder::new(raw_db.key_value().clone(), params.pruning), - secondary: secondary, + secondary, writer: params.writer, snappy_buffer: Vec::new(), - final_state_root: root, + final_state_root, guard: params.guard, db: raw_db, }) @@ -170,7 +170,7 @@ impl Restoration { } // finish up restoration. - fn finalize(mut self, engine: &dyn EthEngine) -> Result<(), Error> { + fn finalize(mut self) -> Result<(), Error> { use trie::TrieError; if !self.is_done() { return Ok(()) } @@ -186,7 +186,7 @@ impl Restoration { self.state.finalize(self.manifest.block_number, self.manifest.block_hash)?; // connect out-of-order chunks and verify chain integrity. - self.secondary.finalize(engine)?; + self.secondary.finalize()?; if let Some(writer) = self.writer { writer.finish(self.manifest)?; @@ -340,12 +340,8 @@ impl Service { // replace one the client's database with our own. fn replace_client_db(&self) -> Result<(), Error> { - let migrated_blocks = self.migrate_blocks()?; - info!(target: "snapshot", "Migrated {} ancient blocks", migrated_blocks); - let rest_db = self.restoration_db(); - self.client.restore_db(&*rest_db.to_string_lossy())?; - Ok(()) + self.client.restore_db(&*rest_db.to_string_lossy()) } // Migrate the blocks in the current DB into the new chain @@ -666,9 +662,12 @@ impl Service { // destroy the restoration before replacing databases and snapshot. rest.take() - .map(|r| r.finalize(&*self.engine)) + .map(|r| r.finalize()) .unwrap_or(Ok(()))?; + let migrated_blocks = self.migrate_blocks()?; + info!(target: "snapshot", "Migrated {} ancient blocks", migrated_blocks); + self.replace_client_db()?; if recover { From 020acf11e7b8578314f1d499ea2e7a752b6e036b Mon Sep 17 00:00:00 2001 From: David Palm Date: Wed, 26 Jun 2019 19:06:46 +0200 Subject: [PATCH 03/20] More logs --- ethcore/db/src/keys.rs | 6 ++---- ethcore/src/snapshot/service.rs | 12 ++++++++++-- 2 files changed, 12 insertions(+), 6 deletions(-) diff --git a/ethcore/db/src/keys.rs b/ethcore/db/src/keys.rs index ceab94211ec..d7db42bf6c1 100644 --- a/ethcore/db/src/keys.rs +++ b/ethcore/db/src/keys.rs @@ -205,7 +205,7 @@ pub struct TransactionAddress { } /// Contains all block receipts. -#[derive(Clone, RlpEncodableWrapper, RlpDecodableWrapper, MallocSizeOf)] +#[derive(Debug, Clone, RlpEncodableWrapper, RlpDecodableWrapper, MallocSizeOf)] pub struct BlockReceipts { /// Block receipts pub receipts: Vec, @@ -214,9 +214,7 @@ pub struct BlockReceipts { impl BlockReceipts { /// Create new block receipts wrapper. pub fn new(receipts: Vec) -> Self { - BlockReceipts { - receipts: receipts - } + BlockReceipts { receipts } } } diff --git a/ethcore/src/snapshot/service.rs b/ethcore/src/snapshot/service.rs index 9130e416bf5..252145213b5 100644 --- a/ethcore/src/snapshot/service.rs +++ b/ethcore/src/snapshot/service.rs @@ -412,7 +412,12 @@ impl Service { next_chain.insert_unordered_block(&mut batch, block, block_receipts, Some(parent_total_difficulty), false, true); count += 1; }, - _ => break, + _ => { + error!(target: "snapshot", "migrate_blocks: failed to find receipts and parent total difficulty. Block #{}, parent_hash={:?}, parent_total_difficulty={:?}", + block_number, parent_hash, parent_total_difficulty); + trace!(target: "snapshot", "migrate_blocks: is previous block (#{}) present?: {}", block_number - 1, self.client.block(BlockId::Number(block_number - 1)).is_some()); + break + }, } // Writing changes to DB and logging every now and then @@ -435,7 +440,10 @@ impl Service { // We couldn't reach the targeted hash if parent_hash != target_hash { - error!(target: "snapshot", "migrate_blocks: could not reach the target_hash, parent_hash={:?}, target_hash={:?}, start_hash={:?}", parent_hash, target_hash, start_hash); + error!(target: "snapshot", "migrate_blocks: could not reach the target_hash, parent_hash={:?}, target_hash={:?}, start_hash={:?}, ancient_block_number={:?}, best_block_number={:?}", + parent_hash, target_hash, start_hash, + cur_chain_info.ancient_block_number, cur_chain_info.best_block_number, + ); return Err(::snapshot::error::Error::UnlinkedAncientBlockChain.into()); } From 690b805a011be534c8b284212e14cf87b43535c6 Mon Sep 17 00:00:00 2001 From: David Palm Date: Wed, 26 Jun 2019 19:10:43 +0200 Subject: [PATCH 04/20] Clarify that the percentage may be misleading --- parity/informant.rs | 3 +++ 1 file changed, 3 insertions(+) diff --git a/parity/informant.rs b/parity/informant.rs index b10a54f93f2..d35df5af2c8 100644 --- a/parity/informant.rs +++ b/parity/informant.rs @@ -321,6 +321,9 @@ impl Informant { }, RestorationStatus::Initializing { chunks_done, state_chunks, block_chunks } => { let total_chunks = state_chunks + block_chunks; + // Note that the percentage here can be slightly misleading when + // they have chunks already on disk: we'll import the local + // chunks first and then download the rest. format!("Snapshot initializing ({}/{} chunks restored, {:.0}%)", chunks_done, total_chunks, (chunks_done as f32 / total_chunks as f32) * 100.0) }, _ => String::new(), From c516d1d67533f644ba3fa39159e573d40e77f712 Mon Sep 17 00:00:00 2001 From: David Palm Date: Wed, 26 Jun 2019 19:20:13 +0200 Subject: [PATCH 05/20] Remove replace_client_db() and replace with a straight call to restore_db() --- ethcore/src/snapshot/service.rs | 9 ++------- 1 file changed, 2 insertions(+), 7 deletions(-) diff --git a/ethcore/src/snapshot/service.rs b/ethcore/src/snapshot/service.rs index 252145213b5..07ff877fad2 100644 --- a/ethcore/src/snapshot/service.rs +++ b/ethcore/src/snapshot/service.rs @@ -338,12 +338,6 @@ impl Service { dir } - // replace one the client's database with our own. - fn replace_client_db(&self) -> Result<(), Error> { - let rest_db = self.restoration_db(); - self.client.restore_db(&*rest_db.to_string_lossy()) - } - // Migrate the blocks in the current DB into the new chain fn migrate_blocks(&self) -> Result { // Count the number of migrated blocks @@ -676,7 +670,8 @@ impl Service { let migrated_blocks = self.migrate_blocks()?; info!(target: "snapshot", "Migrated {} ancient blocks", migrated_blocks); - self.replace_client_db()?; + // replace the Client's database with the new one (restart the Client). + self.client.restore_db(&*self.restoration_db().to_string_lossy())?; if recover { let mut reader = self.reader.write(); From 9f6d5d4c98132cf0cd816a6dcf78471280a4a1f0 Mon Sep 17 00:00:00 2001 From: David Palm Date: Thu, 27 Jun 2019 10:21:42 +0200 Subject: [PATCH 06/20] Include the parent_hash in UnlinkedAncientBlockChain errors --- ethcore/src/snapshot/error.rs | 6 +++--- ethcore/src/snapshot/service.rs | 5 ++--- 2 files changed, 5 insertions(+), 6 deletions(-) diff --git a/ethcore/src/snapshot/error.rs b/ethcore/src/snapshot/error.rs index 8381bd4cb9a..05f63a587ba 100644 --- a/ethcore/src/snapshot/error.rs +++ b/ethcore/src/snapshot/error.rs @@ -68,8 +68,8 @@ pub enum Error { BadEpochProof(u64), /// Wrong chunk format. WrongChunkFormat(String), - /// Unlinked ancient block chain - UnlinkedAncientBlockChain, + /// Unlinked ancient block chain; includes the parent hash where linkage failed + UnlinkedAncientBlockChain(H256), } impl error::Error for Error { @@ -108,7 +108,7 @@ impl fmt::Display for Error { Error::SnapshotAborted => write!(f, "Snapshot was aborted."), Error::BadEpochProof(i) => write!(f, "Bad epoch proof for transition to epoch {}", i), Error::WrongChunkFormat(ref msg) => write!(f, "Wrong chunk format: {}", msg), - Error::UnlinkedAncientBlockChain => write!(f, "Unlinked ancient blocks chain"), + Error::UnlinkedAncientBlockChain(parent_hash) => write!(f, "Unlinked ancient blocks chain at parent_hash={}", parent_hash), } } } diff --git a/ethcore/src/snapshot/service.rs b/ethcore/src/snapshot/service.rs index 07ff877fad2..7ed57b2de8c 100644 --- a/ethcore/src/snapshot/service.rs +++ b/ethcore/src/snapshot/service.rs @@ -391,7 +391,7 @@ impl Service { let block = self.client.block(BlockId::Hash(parent_hash)).ok_or_else(|| { error!(target: "snapshot", "migrate_blocks: did not find block from parent_hash={} (start_hash={})", parent_hash, start_hash); - ::snapshot::error::Error::UnlinkedAncientBlockChain + ::snapshot::error::Error::UnlinkedAncientBlockChain(parent_hash) })?; parent_hash = block.parent_hash(); @@ -409,7 +409,6 @@ impl Service { _ => { error!(target: "snapshot", "migrate_blocks: failed to find receipts and parent total difficulty. Block #{}, parent_hash={:?}, parent_total_difficulty={:?}", block_number, parent_hash, parent_total_difficulty); - trace!(target: "snapshot", "migrate_blocks: is previous block (#{}) present?: {}", block_number - 1, self.client.block(BlockId::Number(block_number - 1)).is_some()); break }, } @@ -438,7 +437,7 @@ impl Service { parent_hash, target_hash, start_hash, cur_chain_info.ancient_block_number, cur_chain_info.best_block_number, ); - return Err(::snapshot::error::Error::UnlinkedAncientBlockChain.into()); + return Err(::snapshot::error::Error::UnlinkedAncientBlockChain(parent_hash).into()); } // Update best ancient block in the Next Chain From 5e2bfb98d30664f9ec0950e1ef66dab5e6b07950 Mon Sep 17 00:00:00 2001 From: David Palm Date: Thu, 27 Jun 2019 12:22:57 +0200 Subject: [PATCH 07/20] Add a new RestorationStatus varian: Finalizing (as it can take a loooong while) Call abort_restore() when restoration fails --- ethcore/src/snapshot/consensus/authority.rs | 1 + ethcore/src/snapshot/consensus/work.rs | 8 ++++---- ethcore/src/snapshot/service.rs | 7 ++++--- ethcore/sync/src/chain/handler.rs | 8 ++++++-- ethcore/sync/src/chain/mod.rs | 5 ++++- ethcore/types/src/restoration_status.rs | 1 + 6 files changed, 20 insertions(+), 10 deletions(-) diff --git a/ethcore/src/snapshot/consensus/authority.rs b/ethcore/src/snapshot/consensus/authority.rs index 7ac5e73d854..d02612b0692 100644 --- a/ethcore/src/snapshot/consensus/authority.rs +++ b/ethcore/src/snapshot/consensus/authority.rs @@ -358,6 +358,7 @@ impl Rebuilder for ChunkRebuilder { None => return Err(Error::WrongChunkFormat("Warp target block not included.".into()).into()), }; + trace!(target: "snapshot", "rebuilder, finalize: verifying {} unverified first blocks", self.unverified_firsts.len()); // verify the first entries of chunks we couldn't before. // we store all last verifiers, but not all firsts. // match each unverified first epoch with a last epoch verifier. diff --git a/ethcore/src/snapshot/consensus/work.rs b/ethcore/src/snapshot/consensus/work.rs index 313e5650a94..1f7f95d1252 100644 --- a/ethcore/src/snapshot/consensus/work.rs +++ b/ethcore/src/snapshot/consensus/work.rs @@ -208,15 +208,15 @@ impl PowRebuilder { /// Create a new PowRebuilder. fn new(chain: BlockChain, db: Arc, manifest: &ManifestData, snapshot_blocks: u64) -> Result { Ok(PowRebuilder { - chain: chain, - db: db, + chain, + db, rng: OsRng::new().map_err(|e| format!("{}", e))?, disconnected: Vec::new(), best_number: manifest.block_number, best_hash: manifest.block_hash, best_root: manifest.state_root, fed_blocks: 0, - snapshot_blocks: snapshot_blocks, + snapshot_blocks, }) } } @@ -300,7 +300,7 @@ impl Rebuilder for PowRebuilder { /// Glue together any disconnected chunks and check that the chain is complete. fn finalize(&mut self) -> Result<(), ::error::Error> { let mut batch = self.db.transaction(); - + trace!(target: "snapshot", "rebuilder, finalize: inserting {} disconnected chunks", self.disconnected.len()); for (first_num, first_hash) in self.disconnected.drain(..) { let parent_num = first_num - 1; diff --git a/ethcore/src/snapshot/service.rs b/ethcore/src/snapshot/service.rs index 7ed57b2de8c..06ba08b56ac 100644 --- a/ethcore/src/snapshot/service.rs +++ b/ethcore/src/snapshot/service.rs @@ -658,6 +658,7 @@ impl Service { // lead to deadlock. fn finalize_restoration(&self, rest: &mut Option) -> Result<(), Error> { trace!(target: "snapshot", "finalizing restoration"); + *self.status.lock() = RestorationStatus::Finalizing; let recover = rest.as_ref().map_or(false, |rest| rest.writer.is_some()); @@ -705,7 +706,7 @@ impl Service { Err(e) => { // TODO: after this we're sometimes deadlocked warn!("Encountered error during snapshot restoration: {}", e); - *self.restoration.lock() = None; + self.abort_restore(); *self.status.lock() = RestorationStatus::Failed; let _ = fs::remove_dir_all(self.restoration_dir()); } @@ -716,8 +717,8 @@ impl Service { fn feed_chunk_with_restoration(&self, restoration: &mut Option, hash: H256, chunk: &[u8], is_state: bool) -> Result<(), Error> { let (result, db) = { match self.status() { - RestorationStatus::Inactive | RestorationStatus::Failed => { - trace!(target: "snapshot", "Tried to restore chunk {:x} while inactive or failed", hash); + RestorationStatus::Inactive | RestorationStatus::Failed | RestorationStatus::Finalizing => { + trace!(target: "snapshot", "Tried to restore chunk {:x} while inactive, failed or finalizing", hash); return Ok(()); }, RestorationStatus::Ongoing { .. } | RestorationStatus::Initializing { .. } => { diff --git a/ethcore/sync/src/chain/handler.rs b/ethcore/sync/src/chain/handler.rs index afd0b4ff227..ada5058dc9c 100644 --- a/ethcore/sync/src/chain/handler.rs +++ b/ethcore/sync/src/chain/handler.rs @@ -256,7 +256,7 @@ impl SyncHandler { return Err(DownloaderImportError::Invalid); } match io.chain().block_status(BlockId::Hash(hash.clone())) { - BlockStatus::InChain => { + BlockStatus::InChain => { trace!(target: "sync", "New block hash already in chain {:?}", hash); }, BlockStatus::Queued => { @@ -529,10 +529,14 @@ impl SyncHandler { sync.snapshot.clear(); return Ok(()); }, - RestorationStatus::Initializing { .. } => { + RestorationStatus::Initializing { .. } => { trace!(target: "warp", "{}: Snapshot restoration is initializing", peer_id); return Ok(()); } + RestorationStatus::Finalizing => { + trace!(target: "warp", "{}: Snapshot finalizing restoration", peer_id); + return Ok(()); + } RestorationStatus::Ongoing { .. } => { trace!(target: "sync", "{}: Snapshot restoration is ongoing", peer_id); }, diff --git a/ethcore/sync/src/chain/mod.rs b/ethcore/sync/src/chain/mod.rs index bde38cda399..0e4e95495b5 100644 --- a/ethcore/sync/src/chain/mod.rs +++ b/ethcore/sync/src/chain/mod.rs @@ -1210,7 +1210,7 @@ impl ChainSync { RestorationStatus::Inactive | RestorationStatus::Failed => { self.set_state(SyncState::SnapshotWaiting); }, - RestorationStatus::Initializing { .. } | RestorationStatus::Ongoing { .. } => (), + RestorationStatus::Initializing { .. } | RestorationStatus::Ongoing { .. } | RestorationStatus::Finalizing => (), }, SyncState::SnapshotWaiting => { match io.snapshot_service().status() { @@ -1221,6 +1221,9 @@ impl ChainSync { RestorationStatus::Initializing { .. } => { trace!(target:"sync", "Snapshot restoration is initializing"); }, + RestorationStatus::Finalizing { .. } => { + trace!(target:"sync", "Snapshot finalizing restoration"); + }, RestorationStatus::Ongoing { state_chunks_done, block_chunks_done, .. } => { if !self.snapshot.is_complete() && self.snapshot.done_chunks() - (state_chunks_done + block_chunks_done) as usize <= MAX_SNAPSHOT_CHUNKS_DOWNLOAD_AHEAD { trace!(target:"sync", "Resuming snapshot sync"); diff --git a/ethcore/types/src/restoration_status.rs b/ethcore/types/src/restoration_status.rs index d924a46460e..f02aa118c80 100644 --- a/ethcore/types/src/restoration_status.rs +++ b/ethcore/types/src/restoration_status.rs @@ -41,6 +41,7 @@ pub enum RestorationStatus { /// Number of block chunks completed. block_chunks_done: u32, }, + Finalizing, /// Failed restoration. Failed, } From 62c65aa0273e472dc75c37a2894877d2294dc6dd Mon Sep 17 00:00:00 2001 From: David Palm Date: Thu, 27 Jun 2019 12:25:05 +0200 Subject: [PATCH 08/20] Add missing cases for new variant --- parity/informant.rs | 3 +++ parity/snapshot.rs | 1 + 2 files changed, 4 insertions(+) diff --git a/parity/informant.rs b/parity/informant.rs index d35df5af2c8..14400d58f08 100644 --- a/parity/informant.rs +++ b/parity/informant.rs @@ -326,6 +326,9 @@ impl Informant { // chunks first and then download the rest. format!("Snapshot initializing ({}/{} chunks restored, {:.0}%)", chunks_done, total_chunks, (chunks_done as f32 / total_chunks as f32) * 100.0) }, + RestorationStatus::Finalizing => { + format!("Snapshot finalization under way") + } _ => String::new(), } ) diff --git a/parity/snapshot.rs b/parity/snapshot.rs index 269965c3355..c1d2a77e3fd 100644 --- a/parity/snapshot.rs +++ b/parity/snapshot.rs @@ -123,6 +123,7 @@ fn restore_using(snapshot: Arc, reader: &R, match snapshot.status() { RestorationStatus::Ongoing { .. } => Err("Snapshot file is incomplete and missing chunks.".into()), RestorationStatus::Initializing { .. } => Err("Snapshot restoration is still initializing.".into()), + RestorationStatus::Finalizing => Err("Snapshot restoration is still finalizing.".into()), RestorationStatus::Failed => Err("Snapshot restoration failed.".into()), RestorationStatus::Inactive => { info!("Restoration complete."); From 947d1e4376743d19ae4bcffe0146a2516336e705 Mon Sep 17 00:00:00 2001 From: David Palm Date: Thu, 27 Jun 2019 13:20:40 +0200 Subject: [PATCH 09/20] typos --- ethcore/blockchain/src/blockchain.rs | 5 +---- ethcore/src/snapshot/service.rs | 2 +- 2 files changed, 2 insertions(+), 5 deletions(-) diff --git a/ethcore/blockchain/src/blockchain.rs b/ethcore/blockchain/src/blockchain.rs index dbe18f25310..f1350f957f0 100644 --- a/ethcore/blockchain/src/blockchain.rs +++ b/ethcore/blockchain/src/blockchain.rs @@ -652,10 +652,7 @@ impl BlockChain { // and write them if let (Some(hash), Some(number)) = (best_ancient, best_ancient_number) { let mut best_ancient_block = bc.best_ancient_block.write(); - *best_ancient_block = Some(BestAncientBlock { - hash: hash, - number: number, - }); + *best_ancient_block = Some(BestAncientBlock { hash, number }); } } diff --git a/ethcore/src/snapshot/service.rs b/ethcore/src/snapshot/service.rs index 06ba08b56ac..0a366275894 100644 --- a/ethcore/src/snapshot/service.rs +++ b/ethcore/src/snapshot/service.rs @@ -369,7 +369,7 @@ impl Service { trace!(target: "snapshot", "Trying to import ancient blocks until {}", highest_block_num); // Here we start from the highest block number and go backward to 0, - // thus starting at `highest_block_num` and targetting `0`. + // thus starting at `highest_block_num` and targeting `0`. let target_hash = self.client.block_hash(BlockId::Number(0))?; let start_hash = self.client.block_hash(BlockId::Number(highest_block_num))?; From d9ab3b942b6510e05554d5bab65cfdc273e3c47a Mon Sep 17 00:00:00 2001 From: David Palm Date: Fri, 28 Jun 2019 11:36:35 +0200 Subject: [PATCH 10/20] Typo and derive Debug --- ethcore/blockchain/src/best_block.rs | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/ethcore/blockchain/src/best_block.rs b/ethcore/blockchain/src/best_block.rs index 20f247391dc..cddb798358d 100644 --- a/ethcore/blockchain/src/best_block.rs +++ b/ethcore/blockchain/src/best_block.rs @@ -24,7 +24,8 @@ use common_types::header::Header; /// For GHOST fork-choice rule it would typically describe the block with highest /// combined difficulty (usually the block with the highest block number). /// -/// Sometimes refered as 'latest block'. +/// Sometimes referred as 'latest block'. +#[derive(Debug)] pub struct BestBlock { /// Best block decoded header. pub header: Header, @@ -35,7 +36,7 @@ pub struct BestBlock { } /// Best ancient block info. If the blockchain has a gap this keeps track of where it starts. -#[derive(Default)] +#[derive(Debug, Default)] pub struct BestAncientBlock { /// Best block hash. pub hash: H256, From 72c58b5319d1d7d9299f7aeded0ff4e6043e38fa Mon Sep 17 00:00:00 2001 From: David Palm Date: Fri, 28 Jun 2019 11:37:01 +0200 Subject: [PATCH 11/20] Do not attempt to salvage existing blocks unless they form a complete chain back to genesis --- ethcore/src/snapshot/service.rs | 23 ++++++++++++++++++++--- 1 file changed, 20 insertions(+), 3 deletions(-) diff --git a/ethcore/src/snapshot/service.rs b/ethcore/src/snapshot/service.rs index 0a366275894..935ad59ae9f 100644 --- a/ethcore/src/snapshot/service.rs +++ b/ethcore/src/snapshot/service.rs @@ -352,11 +352,27 @@ impl Service { // The old database looks like this: // [genesis, best_ancient_block] ... [first_block, best_block] - // If we are fully synced neither `best_ancient_block` nor `first_block` is set, and we can assume that the whole range from [genesis, best_block] is imported. - // The new database only contains the tip of the chain ([first_block, best_block]), + // If we are fully synced neither `best_ancient_block` nor `first_block` is set, and we can + // assume that the whole range from [genesis, best_block] is imported. + // The new database only contains the tip of the chain ([new_first_block, new_best_block]), // so the useful set of blocks is defined as: // [0 ... min(new.first_block, best_ancient_block or best_block)] + // + // If, for whatever reason, the old db does not have ancient blocks (i.e. + // `best_ancient_block` is `None`) AND a non-zero `first_block`, such that the old db looks + // like [old_first_block..old_best_block] (which may or may not partially overlap with + // [new_first_block..new_best_block]) we do the conservative thing and do not migrate the + // old blocks. let find_range = || -> Option<(H256, H256)> { + // TODO: In theory, if the current best_block is > new first_block (i.e. they overlap) + // we could salvage them but what if there's been a re-org at the boundary and the two + // chains do not match anymore? Would it actually work? + if cur_chain_info.ancient_block_number.is_none() && cur_chain_info.first_block_number.unwrap_or(0) > 0 { + warn!(target: "blockchain", "blocks in the current DB do not stretch back to genesis; can't salvage them into the new DB. In current DB first block : {:?}/#{:?}, best block: {:?}, #{:?}", + cur_chain_info.first_block_hash, cur_chain_info.first_block_number, + cur_chain_info.best_block_number, cur_chain_info.best_block_hash); + return None; + } let next_available_from = next_chain_info.first_block_number?; let cur_available_to = cur_chain_info.ancient_block_number.unwrap_or(cur_chain_info.best_block_number); @@ -366,7 +382,8 @@ impl Service { return None; } - trace!(target: "snapshot", "Trying to import ancient blocks until {}", highest_block_num); + trace!(target: "snapshot", "Trying to import ancient blocks until {}. First block in new chain=#{}, first block in old chain=#{:?}, best block in old chain=#{}", highest_block_num, + next_available_from, cur_chain_info.first_block_number, cur_chain_info.best_block_number); // Here we start from the highest block number and go backward to 0, // thus starting at `highest_block_num` and targeting `0`. From f027d4b4cb7b6c23fceec528c1711886ba9cfe4e Mon Sep 17 00:00:00 2001 From: David Palm Date: Fri, 28 Jun 2019 12:00:55 +0200 Subject: [PATCH 12/20] Fix test --- Cargo.toml | 2 +- ethcore/blockchain/src/blockchain.rs | 49 ++++++++++++++++++++- ethcore/src/snapshot/tests/proof_of_work.rs | 2 +- 3 files changed, 49 insertions(+), 4 deletions(-) diff --git a/Cargo.toml b/Cargo.toml index 39a9bbd3645..ae9c807f176 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -121,7 +121,7 @@ name = "parity" [profile.release] debug = false -lto = true +lto = false [workspace] # This should only list projects that are not diff --git a/ethcore/blockchain/src/blockchain.rs b/ethcore/blockchain/src/blockchain.rs index f1350f957f0..335d838993c 100644 --- a/ethcore/blockchain/src/blockchain.rs +++ b/ethcore/blockchain/src/blockchain.rs @@ -549,11 +549,13 @@ impl BlockChain { pending_transaction_addresses: RwLock::new(HashMap::new()), }; + trace!(target: "blockchain", "new: finding best block"); // load best block let best_block_hash = match bc.db.key_value().get(db::COL_EXTRA, b"best") .expect("Low-level database error when fetching 'best' block. Some issue with disk?") { Some(best) => { + trace!(target: "blockchain", "new: best block found: {}", H256::from_slice(&best)); H256::from_slice(&best) } None => { @@ -580,6 +582,7 @@ impl BlockChain { batch.put(db::COL_EXTRA, b"best", hash.as_bytes()); bc.db.key_value().write(batch).expect("Low level database error when fetching 'best' block. Some issue with disk?"); + trace!(target: "blockchain", "new: no best block found, had to add genesis to cache: hash={}, block number #{}", hash, header.number()); hash } }; @@ -600,6 +603,7 @@ impl BlockChain { block: best_block_rlp, }; } + trace!(target: "blockchain", "new: best block: {}/#{}", best_block_hash, bc.best_block.read().header.number()); { let best_block_number = bc.best_block.read().header.number(); @@ -607,20 +611,56 @@ impl BlockChain { let raw_first = bc.db.key_value().get(db::COL_EXTRA, b"first") .expect("Low level database error when fetching 'first' block. Some issue with disk?") .map(|v| v.into_vec()); + let mut best_ancient = bc.db.key_value().get(db::COL_EXTRA, b"ancient") .expect("Low level database error when fetching 'best ancient' block. Some issue with disk?") .map(|h| H256::from_slice(&h)); + trace!(target: "blockchain", "new: best ancient block hash={:?}", best_ancient); + let best_ancient_number; if best_ancient.is_none() && best_block_number > 1 && bc.block_hash(1).is_none() { best_ancient = Some(bc.genesis_hash()); best_ancient_number = Some(0); + trace!(target: "blockchain", "new: no best ancient block; using genesis {}/#{}", bc.genesis_hash(), 0); } else { - best_ancient_number = best_ancient.as_ref().and_then(|h| bc.block_number(h)); + if best_ancient.is_some() { + best_ancient_number = best_ancient.as_ref().and_then(|h| bc.block_number(h)); + trace!(target: "blockchain", "new: final best ancient block: {}", best_ancient.unwrap()); + trace!(target: "blockchain", "new: final best ancient block: #{:?}", best_ancient_number); + } else { + best_ancient_number = Some(0); + trace!(target: "blockchain", "new: no ancient block found. Hmm."); + + let f = H256::from_slice(&raw_first.clone().unwrap()); + let f_blk = bc.block(&f); + let mut block = f_blk.unwrap(); + let mut ranges: Vec<((u64, H256),(u64, H256))> = vec![] ; + let mut range = ((0, H256::zero()), (0, H256::zero())); + for i in (0..block.number()).rev() { + if let Some(h) = bc.block_hash(i) { +// trace!(target: "blockchain", " Found block #{}/{}", i, h); + range.0 = (i, h); + } else { + range.1 = (i, H256::zero()); + ranges.push(range.clone()); + range = ((0, H256::zero()), (0, H256::zero())); + } + } + trace!(target: "blockchain", " DONE CHECKING. Ranges: {:?}", ranges); +// while let Some(b) = bc.block(&block.parent_hash()) { +// trace!(target: "blockchain", " Found block #{}", b.number()); +// block = b; +// } +// +// trace!(target: "blockchain", " LAST Found block {}/#{}", block.hash(), block.number()); + + } } // binary search for the first block. match raw_first { None => { + trace!(target: "blockchain", "new: no first block"); let (mut f, mut hash) = (best_block_number, best_block_hash); let mut l = best_ancient_number.unwrap_or(0); @@ -637,7 +677,7 @@ impl BlockChain { } if hash != bc.genesis_hash() { - trace!("First block calculated: {:?}", hash); + trace!(target: "blockchain", "First block calculated: {:?}", hash); let mut batch = db.key_value().transaction(); batch.put(db::COL_EXTRA, b"first", hash.as_bytes()); db.key_value().write(batch).expect("Low level database error when writing 'first' block. Some issue with disk?"); @@ -646,13 +686,18 @@ impl BlockChain { }, Some(raw_first) => { bc.first_block = Some(H256::from_slice(&raw_first)); + trace!(target: "blockchain", "new: first block from disk: {}/#{}", bc.first_block.unwrap(), bc.first_block_number().unwrap()); }, } // and write them if let (Some(hash), Some(number)) = (best_ancient, best_ancient_number) { + trace!(target: "blockchain", "new: figured out the best ancient block: {}/#{} – writing to the DB", hash, number); + let mut best_ancient_block = bc.best_ancient_block.write(); *best_ancient_block = Some(BestAncientBlock { hash, number }); + } else { + warn!(target: "blockchain", "new: could not figure out what the best ancient block is; {:?}, {:?}", best_ancient, best_ancient_number); } } diff --git a/ethcore/src/snapshot/tests/proof_of_work.rs b/ethcore/src/snapshot/tests/proof_of_work.rs index fb714e667f5..fa58c360bb9 100644 --- a/ethcore/src/snapshot/tests/proof_of_work.rs +++ b/ethcore/src/snapshot/tests/proof_of_work.rs @@ -93,7 +93,7 @@ fn chunk_and_restore(amount: u64) { rebuilder.feed(&chunk, engine.as_ref(), &flag).unwrap(); } - rebuilder.finalize(engine.as_ref()).unwrap(); + rebuilder.finalize().expect("rebuilder failed finalization"); drop(rebuilder); // and test it. From 2f5a1c6f6d4dd600ec6050cbd1e2c316e1c8af44 Mon Sep 17 00:00:00 2001 From: David Palm Date: Fri, 28 Jun 2019 12:04:22 +0200 Subject: [PATCH 13/20] Revert "Fix test" This reverts commit f027d4b4cb7b6c23fceec528c1711886ba9cfe4e. --- Cargo.toml | 2 +- ethcore/blockchain/src/blockchain.rs | 49 +-------------------- ethcore/src/snapshot/tests/proof_of_work.rs | 2 +- 3 files changed, 4 insertions(+), 49 deletions(-) diff --git a/Cargo.toml b/Cargo.toml index ae9c807f176..39a9bbd3645 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -121,7 +121,7 @@ name = "parity" [profile.release] debug = false -lto = false +lto = true [workspace] # This should only list projects that are not diff --git a/ethcore/blockchain/src/blockchain.rs b/ethcore/blockchain/src/blockchain.rs index 335d838993c..f1350f957f0 100644 --- a/ethcore/blockchain/src/blockchain.rs +++ b/ethcore/blockchain/src/blockchain.rs @@ -549,13 +549,11 @@ impl BlockChain { pending_transaction_addresses: RwLock::new(HashMap::new()), }; - trace!(target: "blockchain", "new: finding best block"); // load best block let best_block_hash = match bc.db.key_value().get(db::COL_EXTRA, b"best") .expect("Low-level database error when fetching 'best' block. Some issue with disk?") { Some(best) => { - trace!(target: "blockchain", "new: best block found: {}", H256::from_slice(&best)); H256::from_slice(&best) } None => { @@ -582,7 +580,6 @@ impl BlockChain { batch.put(db::COL_EXTRA, b"best", hash.as_bytes()); bc.db.key_value().write(batch).expect("Low level database error when fetching 'best' block. Some issue with disk?"); - trace!(target: "blockchain", "new: no best block found, had to add genesis to cache: hash={}, block number #{}", hash, header.number()); hash } }; @@ -603,7 +600,6 @@ impl BlockChain { block: best_block_rlp, }; } - trace!(target: "blockchain", "new: best block: {}/#{}", best_block_hash, bc.best_block.read().header.number()); { let best_block_number = bc.best_block.read().header.number(); @@ -611,56 +607,20 @@ impl BlockChain { let raw_first = bc.db.key_value().get(db::COL_EXTRA, b"first") .expect("Low level database error when fetching 'first' block. Some issue with disk?") .map(|v| v.into_vec()); - let mut best_ancient = bc.db.key_value().get(db::COL_EXTRA, b"ancient") .expect("Low level database error when fetching 'best ancient' block. Some issue with disk?") .map(|h| H256::from_slice(&h)); - trace!(target: "blockchain", "new: best ancient block hash={:?}", best_ancient); - let best_ancient_number; if best_ancient.is_none() && best_block_number > 1 && bc.block_hash(1).is_none() { best_ancient = Some(bc.genesis_hash()); best_ancient_number = Some(0); - trace!(target: "blockchain", "new: no best ancient block; using genesis {}/#{}", bc.genesis_hash(), 0); } else { - if best_ancient.is_some() { - best_ancient_number = best_ancient.as_ref().and_then(|h| bc.block_number(h)); - trace!(target: "blockchain", "new: final best ancient block: {}", best_ancient.unwrap()); - trace!(target: "blockchain", "new: final best ancient block: #{:?}", best_ancient_number); - } else { - best_ancient_number = Some(0); - trace!(target: "blockchain", "new: no ancient block found. Hmm."); - - let f = H256::from_slice(&raw_first.clone().unwrap()); - let f_blk = bc.block(&f); - let mut block = f_blk.unwrap(); - let mut ranges: Vec<((u64, H256),(u64, H256))> = vec![] ; - let mut range = ((0, H256::zero()), (0, H256::zero())); - for i in (0..block.number()).rev() { - if let Some(h) = bc.block_hash(i) { -// trace!(target: "blockchain", " Found block #{}/{}", i, h); - range.0 = (i, h); - } else { - range.1 = (i, H256::zero()); - ranges.push(range.clone()); - range = ((0, H256::zero()), (0, H256::zero())); - } - } - trace!(target: "blockchain", " DONE CHECKING. Ranges: {:?}", ranges); -// while let Some(b) = bc.block(&block.parent_hash()) { -// trace!(target: "blockchain", " Found block #{}", b.number()); -// block = b; -// } -// -// trace!(target: "blockchain", " LAST Found block {}/#{}", block.hash(), block.number()); - - } + best_ancient_number = best_ancient.as_ref().and_then(|h| bc.block_number(h)); } // binary search for the first block. match raw_first { None => { - trace!(target: "blockchain", "new: no first block"); let (mut f, mut hash) = (best_block_number, best_block_hash); let mut l = best_ancient_number.unwrap_or(0); @@ -677,7 +637,7 @@ impl BlockChain { } if hash != bc.genesis_hash() { - trace!(target: "blockchain", "First block calculated: {:?}", hash); + trace!("First block calculated: {:?}", hash); let mut batch = db.key_value().transaction(); batch.put(db::COL_EXTRA, b"first", hash.as_bytes()); db.key_value().write(batch).expect("Low level database error when writing 'first' block. Some issue with disk?"); @@ -686,18 +646,13 @@ impl BlockChain { }, Some(raw_first) => { bc.first_block = Some(H256::from_slice(&raw_first)); - trace!(target: "blockchain", "new: first block from disk: {}/#{}", bc.first_block.unwrap(), bc.first_block_number().unwrap()); }, } // and write them if let (Some(hash), Some(number)) = (best_ancient, best_ancient_number) { - trace!(target: "blockchain", "new: figured out the best ancient block: {}/#{} – writing to the DB", hash, number); - let mut best_ancient_block = bc.best_ancient_block.write(); *best_ancient_block = Some(BestAncientBlock { hash, number }); - } else { - warn!(target: "blockchain", "new: could not figure out what the best ancient block is; {:?}, {:?}", best_ancient, best_ancient_number); } } diff --git a/ethcore/src/snapshot/tests/proof_of_work.rs b/ethcore/src/snapshot/tests/proof_of_work.rs index fa58c360bb9..fb714e667f5 100644 --- a/ethcore/src/snapshot/tests/proof_of_work.rs +++ b/ethcore/src/snapshot/tests/proof_of_work.rs @@ -93,7 +93,7 @@ fn chunk_and_restore(amount: u64) { rebuilder.feed(&chunk, engine.as_ref(), &flag).unwrap(); } - rebuilder.finalize().expect("rebuilder failed finalization"); + rebuilder.finalize(engine.as_ref()).unwrap(); drop(rebuilder); // and test it. From e019c8ebf42c974e2d658172fbc2aaa1e14e59aa Mon Sep 17 00:00:00 2001 From: David Palm Date: Fri, 28 Jun 2019 12:05:12 +0200 Subject: [PATCH 14/20] Fix test again --- ethcore/src/snapshot/tests/proof_of_work.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/ethcore/src/snapshot/tests/proof_of_work.rs b/ethcore/src/snapshot/tests/proof_of_work.rs index fb714e667f5..4aa444229a2 100644 --- a/ethcore/src/snapshot/tests/proof_of_work.rs +++ b/ethcore/src/snapshot/tests/proof_of_work.rs @@ -93,7 +93,7 @@ fn chunk_and_restore(amount: u64) { rebuilder.feed(&chunk, engine.as_ref(), &flag).unwrap(); } - rebuilder.finalize(engine.as_ref()).unwrap(); + rebuilder.finalize().unwrap(); drop(rebuilder); // and test it. From 6bf1ad3e14388f0188f88d481afb3ba1ed05bdcb Mon Sep 17 00:00:00 2001 From: David Palm Date: Fri, 28 Jun 2019 13:00:56 +0200 Subject: [PATCH 15/20] Update comment --- ethcore/src/snapshot/service.rs | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/ethcore/src/snapshot/service.rs b/ethcore/src/snapshot/service.rs index 935ad59ae9f..04daf09e8b8 100644 --- a/ethcore/src/snapshot/service.rs +++ b/ethcore/src/snapshot/service.rs @@ -364,9 +364,9 @@ impl Service { // [new_first_block..new_best_block]) we do the conservative thing and do not migrate the // old blocks. let find_range = || -> Option<(H256, H256)> { - // TODO: In theory, if the current best_block is > new first_block (i.e. they overlap) - // we could salvage them but what if there's been a re-org at the boundary and the two - // chains do not match anymore? Would it actually work? + // In theory, if the current best_block is > new first_block (i.e. ranges overlap) + // we could salvage them but what if there's been a re-org at the boundary and the two + // chains do not match anymore? We'd have to check the existing blocks carefully. if cur_chain_info.ancient_block_number.is_none() && cur_chain_info.first_block_number.unwrap_or(0) > 0 { warn!(target: "blockchain", "blocks in the current DB do not stretch back to genesis; can't salvage them into the new DB. In current DB first block : {:?}/#{:?}, best block: {:?}, #{:?}", cur_chain_info.first_block_hash, cur_chain_info.first_block_number, From 12fd8563a9d6a4f8d6c8182e235e13a2ce72ee24 Mon Sep 17 00:00:00 2001 From: David Palm Date: Fri, 28 Jun 2019 14:34:50 +0200 Subject: [PATCH 16/20] Be careful about locks --- ethcore/src/snapshot/service.rs | 16 +++++++++++----- 1 file changed, 11 insertions(+), 5 deletions(-) diff --git a/ethcore/src/snapshot/service.rs b/ethcore/src/snapshot/service.rs index 4065c17fb92..fcdfadc37d2 100644 --- a/ethcore/src/snapshot/service.rs +++ b/ethcore/src/snapshot/service.rs @@ -43,6 +43,7 @@ use bytes::Bytes; use journaldb::Algorithm; use kvdb::DBTransaction; use snappy; +use snapshot::error::Error::UnlinkedAncientBlockChain; /// Helper for removing directories in case of error. struct Guard(bool, PathBuf); @@ -408,7 +409,7 @@ impl Service { let block = self.client.block(BlockId::Hash(parent_hash)).ok_or_else(|| { error!(target: "snapshot", "migrate_blocks: did not find block from parent_hash={} (start_hash={})", parent_hash, start_hash); - ::snapshot::error::Error::UnlinkedAncientBlockChain(parent_hash) + UnlinkedAncientBlockChain(parent_hash) })?; parent_hash = block.parent_hash(); @@ -454,7 +455,7 @@ impl Service { parent_hash, target_hash, start_hash, cur_chain_info.ancient_block_number, cur_chain_info.best_block_number, ); - return Err(::snapshot::error::Error::UnlinkedAncientBlockChain(parent_hash).into()); + return Err(UnlinkedAncientBlockChain(parent_hash).into()); } // Update best ancient block in the Next Chain @@ -716,15 +717,20 @@ impl Service { /// Feed a chunk of either kind (block or state). no-op if no restoration or status is wrong. fn feed_chunk(&self, hash: H256, chunk: &[u8], is_state: bool) { // TODO: be able to process block chunks and state chunks at same time? - let mut restoration = self.restoration.lock(); - match self.feed_chunk_with_restoration(&mut restoration, hash, chunk, is_state) { + let r = { + let mut restoration = self.restoration.lock(); + self.feed_chunk_with_restoration(&mut restoration, hash, chunk, is_state) + }; + match r { Ok(()) | Err(Error::Snapshot(SnapshotError::RestorationAborted)) => (), Err(e) => { // TODO: after this we're sometimes deadlocked warn!("Encountered error during snapshot restoration: {}", e); self.abort_restore(); - *self.status.lock() = RestorationStatus::Failed; + if let Some(mut status) = self.status.try_lock_for(std::time::Duration::from_millis(10)) { + *status = RestorationStatus::Failed; + } let _ = fs::remove_dir_all(self.restoration_dir()); } } From f577c8fe08032c32f352190e1969766bbce5af03 Mon Sep 17 00:00:00 2001 From: David Palm Date: Fri, 28 Jun 2019 14:53:16 +0200 Subject: [PATCH 17/20] fix test failure --- ethcore/src/snapshot/tests/helpers.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/ethcore/src/snapshot/tests/helpers.rs b/ethcore/src/snapshot/tests/helpers.rs index 1873d05b7f9..a6e516b1b1a 100644 --- a/ethcore/src/snapshot/tests/helpers.rs +++ b/ethcore/src/snapshot/tests/helpers.rs @@ -187,5 +187,5 @@ pub fn restore( trace!(target: "snapshot", "finalizing"); state.finalize(manifest.block_number, manifest.block_hash)?; - secondary.finalize(engine) + secondary.finalize() } From 323edb731c7da084556cf0597a1cb0dbff817ae9 Mon Sep 17 00:00:00 2001 From: David Palm Date: Mon, 1 Jul 2019 09:59:17 +0200 Subject: [PATCH 18/20] Do not defer returning an error when the chain is broken --- ethcore/src/snapshot/service.rs | 20 +++++++------------- 1 file changed, 7 insertions(+), 13 deletions(-) diff --git a/ethcore/src/snapshot/service.rs b/ethcore/src/snapshot/service.rs index fcdfadc37d2..560e5193ec1 100644 --- a/ethcore/src/snapshot/service.rs +++ b/ethcore/src/snapshot/service.rs @@ -369,7 +369,7 @@ impl Service { // we could salvage them but what if there's been a re-org at the boundary and the two // chains do not match anymore? We'd have to check the existing blocks carefully. if cur_chain_info.ancient_block_number.is_none() && cur_chain_info.first_block_number.unwrap_or(0) > 0 { - warn!(target: "blockchain", "blocks in the current DB do not stretch back to genesis; can't salvage them into the new DB. In current DB first block : {:?}/#{:?}, best block: {:?}, #{:?}", + info!(target: "blockchain", "blocks in the current DB do not stretch back to genesis; can't salvage them into the new DB. In current DB first block : {:?}/#{:?}, best block: {:?}, #{:?}", cur_chain_info.first_block_hash, cur_chain_info.first_block_number, cur_chain_info.best_block_number, cur_chain_info.best_block_hash); return None; @@ -425,9 +425,12 @@ impl Service { count += 1; }, _ => { - error!(target: "snapshot", "migrate_blocks: failed to find receipts and parent total difficulty. Block #{}, parent_hash={:?}, parent_total_difficulty={:?}", - block_number, parent_hash, parent_total_difficulty); - break + // We couldn't reach the targeted hash + error!(target: "snapshot", "migrate_blocks: failed to find receipts and parent total difficulty; cannot reach the target_hash ({}). Block #{}, parent_hash={:?}, parent_total_difficulty={:?}, start_hash={:?}, ancient_block_number={:?}, best_block_number={:?}", + target_hash, block_number, parent_hash, parent_total_difficulty, + start_hash, cur_chain_info.ancient_block_number, cur_chain_info.best_block_number, + ); + return Err(UnlinkedAncientBlockChain(parent_hash).into()); }, } @@ -449,15 +452,6 @@ impl Service { next_chain.commit(); next_db.key_value().flush().expect("DB flush failed."); - // We couldn't reach the targeted hash - if parent_hash != target_hash { - error!(target: "snapshot", "migrate_blocks: could not reach the target_hash, parent_hash={:?}, target_hash={:?}, start_hash={:?}, ancient_block_number={:?}, best_block_number={:?}", - parent_hash, target_hash, start_hash, - cur_chain_info.ancient_block_number, cur_chain_info.best_block_number, - ); - return Err(UnlinkedAncientBlockChain(parent_hash).into()); - } - // Update best ancient block in the Next Chain next_chain.update_best_ancient_block(&start_hash); Ok(count) From fc220b0f3cbabbe6e40f67e5ddc7214a6f73dbb0 Mon Sep 17 00:00:00 2001 From: David Palm Date: Mon, 1 Jul 2019 13:39:17 +0200 Subject: [PATCH 19/20] Review feedback --- ethcore/src/snapshot/error.rs | 2 +- ethcore/src/snapshot/service.rs | 14 +++++++------- 2 files changed, 8 insertions(+), 8 deletions(-) diff --git a/ethcore/src/snapshot/error.rs b/ethcore/src/snapshot/error.rs index 05f63a587ba..68742e2e178 100644 --- a/ethcore/src/snapshot/error.rs +++ b/ethcore/src/snapshot/error.rs @@ -108,7 +108,7 @@ impl fmt::Display for Error { Error::SnapshotAborted => write!(f, "Snapshot was aborted."), Error::BadEpochProof(i) => write!(f, "Bad epoch proof for transition to epoch {}", i), Error::WrongChunkFormat(ref msg) => write!(f, "Wrong chunk format: {}", msg), - Error::UnlinkedAncientBlockChain(parent_hash) => write!(f, "Unlinked ancient blocks chain at parent_hash={}", parent_hash), + Error::UnlinkedAncientBlockChain(parent_hash) => write!(f, "Unlinked ancient blocks chain at parent_hash={:#x}", parent_hash), } } } diff --git a/ethcore/src/snapshot/service.rs b/ethcore/src/snapshot/service.rs index 560e5193ec1..caf657acde3 100644 --- a/ethcore/src/snapshot/service.rs +++ b/ethcore/src/snapshot/service.rs @@ -360,7 +360,7 @@ impl Service { // [0 ... min(new.first_block, best_ancient_block or best_block)] // // If, for whatever reason, the old db does not have ancient blocks (i.e. - // `best_ancient_block` is `None`) AND a non-zero `first_block`, such that the old db looks + // `best_ancient_block` is `None` AND a non-zero `first_block`), such that the old db looks // like [old_first_block..old_best_block] (which may or may not partially overlap with // [new_first_block..new_best_block]) we do the conservative thing and do not migrate the // old blocks. @@ -369,8 +369,8 @@ impl Service { // we could salvage them but what if there's been a re-org at the boundary and the two // chains do not match anymore? We'd have to check the existing blocks carefully. if cur_chain_info.ancient_block_number.is_none() && cur_chain_info.first_block_number.unwrap_or(0) > 0 { - info!(target: "blockchain", "blocks in the current DB do not stretch back to genesis; can't salvage them into the new DB. In current DB first block : {:?}/#{:?}, best block: {:?}, #{:?}", - cur_chain_info.first_block_hash, cur_chain_info.first_block_number, + info!(target: "blockchain", "blocks in the current DB do not stretch back to genesis; can't salvage them into the new DB. In current DB, first block: #{}/{:#x}, best block: #{}/{:#x}", + cur_chain_info.first_block_number, cur_chain_info.first_block_hash, cur_chain_info.best_block_number, cur_chain_info.best_block_hash); return None; } @@ -383,8 +383,8 @@ impl Service { return None; } - trace!(target: "snapshot", "Trying to import ancient blocks until {}. First block in new chain=#{}, first block in old chain=#{:?}, best block in old chain=#{}", highest_block_num, - next_available_from, cur_chain_info.first_block_number, cur_chain_info.best_block_number); + trace!(target: "snapshot", "Trying to import ancient blocks until {}. First block in new chain=#{}, first block in old chain=#{:?}, best block in old chain=#{}", + highest_block_num, next_available_from, cur_chain_info.first_block_number, cur_chain_info.best_block_number); // Here we start from the highest block number and go backward to 0, // thus starting at `highest_block_num` and targeting `0`. @@ -408,7 +408,7 @@ impl Service { } let block = self.client.block(BlockId::Hash(parent_hash)).ok_or_else(|| { - error!(target: "snapshot", "migrate_blocks: did not find block from parent_hash={} (start_hash={})", parent_hash, start_hash); + error!(target: "snapshot", "migrate_blocks: did not find block from parent_hash={:#x} (start_hash={:#x})", parent_hash, start_hash); UnlinkedAncientBlockChain(parent_hash) })?; parent_hash = block.parent_hash(); @@ -426,7 +426,7 @@ impl Service { }, _ => { // We couldn't reach the targeted hash - error!(target: "snapshot", "migrate_blocks: failed to find receipts and parent total difficulty; cannot reach the target_hash ({}). Block #{}, parent_hash={:?}, parent_total_difficulty={:?}, start_hash={:?}, ancient_block_number={:?}, best_block_number={:?}", + error!(target: "snapshot", "migrate_blocks: failed to find receipts and parent total difficulty; cannot reach the target_hash ({:#x}). Block #{}, parent_hash={:#x}, parent_total_difficulty={:?}, start_hash={:#x}, ancient_block_number={:?}, best_block_number={:?}", target_hash, block_number, parent_hash, parent_total_difficulty, start_hash, cur_chain_info.ancient_block_number, cur_chain_info.best_block_number, ); From 9e17d6187bbd03d77546c0d0c5891fef3786662a Mon Sep 17 00:00:00 2001 From: David Palm Date: Mon, 1 Jul 2019 13:53:53 +0200 Subject: [PATCH 20/20] no hex formatting for Option --- ethcore/src/snapshot/service.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/ethcore/src/snapshot/service.rs b/ethcore/src/snapshot/service.rs index caf657acde3..5e1efe13824 100644 --- a/ethcore/src/snapshot/service.rs +++ b/ethcore/src/snapshot/service.rs @@ -369,7 +369,7 @@ impl Service { // we could salvage them but what if there's been a re-org at the boundary and the two // chains do not match anymore? We'd have to check the existing blocks carefully. if cur_chain_info.ancient_block_number.is_none() && cur_chain_info.first_block_number.unwrap_or(0) > 0 { - info!(target: "blockchain", "blocks in the current DB do not stretch back to genesis; can't salvage them into the new DB. In current DB, first block: #{}/{:#x}, best block: #{}/{:#x}", + info!(target: "blockchain", "blocks in the current DB do not stretch back to genesis; can't salvage them into the new DB. In current DB, first block: #{:?}/{:?}, best block: #{:?}/{:?}", cur_chain_info.first_block_number, cur_chain_info.first_block_hash, cur_chain_info.best_block_number, cur_chain_info.best_block_hash); return None;